From b3fa103cb9cc4a3367b6fad734240c62689b3b5a Mon Sep 17 00:00:00 2001 From: Minghao Li Date: Fri, 24 Jun 2022 11:36:26 +0800 Subject: [PATCH] refactor(sync): add trace log --- source/libs/sync/src/syncMain.c | 42 ++++++++++++++++++++++++--------- 1 file changed, 31 insertions(+), 11 deletions(-) diff --git a/source/libs/sync/src/syncMain.c b/source/libs/sync/src/syncMain.c index 8bbee65369..42ba2b85b1 100644 --- a/source/libs/sync/src/syncMain.c +++ b/source/libs/sync/src/syncMain.c @@ -1322,11 +1322,11 @@ void syncNodeEventLog(const SSyncNode* pSyncNode, char* str) { snprintf(logBuf, sizeof(logBuf), "vgId:%d, sync %s %s, term:%lu, commit:%ld, beginlog:%ld, lastlog:%ld, lastsnapshot:%ld, standby:%d, " "replica-num:%d, " - "lconfig:%ld, changing:%d, %s", + "lconfig:%ld, changing:%d, restore:%d, %s", pSyncNode->vgId, syncUtilState2String(pSyncNode->state), str, pSyncNode->pRaftStore->currentTerm, pSyncNode->commitIndex, logBeginIndex, logLastIndex, snapshot.lastApplyIndex, pSyncNode->pRaftCfg->isStandBy, pSyncNode->replicaNum, pSyncNode->pRaftCfg->lastConfigIndex, - pSyncNode->changing, printStr); + pSyncNode->changing, pSyncNode->restoreFinish, printStr); } else { snprintf(logBuf, sizeof(logBuf), "%s", str); } @@ -1339,11 +1339,11 @@ void syncNodeEventLog(const SSyncNode* pSyncNode, char* str) { snprintf(s, len, "vgId:%d, sync %s %s, term:%lu, commit:%ld, beginlog:%ld, lastlog:%ld, lastsnapshot:%ld, standby:%d, " "replica-num:%d, " - "lconfig:%ld, changing:%d, %s", + "lconfig:%ld, changing:%d, restore:%d, %s", pSyncNode->vgId, syncUtilState2String(pSyncNode->state), str, pSyncNode->pRaftStore->currentTerm, pSyncNode->commitIndex, logBeginIndex, logLastIndex, snapshot.lastApplyIndex, pSyncNode->pRaftCfg->isStandBy, pSyncNode->replicaNum, pSyncNode->pRaftCfg->lastConfigIndex, - pSyncNode->changing, printStr); + pSyncNode->changing, pSyncNode->restoreFinish, printStr); } else { snprintf(s, len, "%s", str); } @@ -1403,14 +1403,34 @@ void syncNodeErrorLog(const SSyncNode* pSyncNode, char* str) { char* syncNode2SimpleStr(const SSyncNode* pSyncNode) { int len = 256; char* s = (char*)taosMemoryMalloc(len); + + SSnapshot snapshot = {.data = NULL, .lastApplyIndex = -1, .lastApplyTerm = 0}; + if (pSyncNode->pFsm->FpGetSnapshotInfo != NULL) { + pSyncNode->pFsm->FpGetSnapshotInfo(pSyncNode->pFsm, &snapshot); + } + SyncIndex logLastIndex = pSyncNode->pLogStore->syncLogLastIndex(pSyncNode->pLogStore); + SyncIndex logBeginIndex = pSyncNode->pLogStore->syncLogBeginIndex(pSyncNode->pLogStore); + snprintf(s, len, - "syncNode: vgId:%d, currentTerm:%lu, commitIndex:%ld, state:%d %s, isStandBy:%d, " - "electTimerLogicClock:%lu, " - "electTimerLogicClockUser:%lu, " - "electTimerMS:%d, replicaNum:%d", - pSyncNode->vgId, pSyncNode->pRaftStore->currentTerm, pSyncNode->commitIndex, pSyncNode->state, - syncUtilState2String(pSyncNode->state), pSyncNode->pRaftCfg->isStandBy, pSyncNode->electTimerLogicClock, - pSyncNode->electTimerLogicClockUser, pSyncNode->electTimerMS, pSyncNode->replicaNum); + "vgId:%d, sync %s, term:%lu, commit:%ld, beginlog:%ld, lastlog:%ld, lastsnapshot:%ld, standby:%d, " + "replica-num:%d, " + "lconfig:%ld, changing:%d, restore:%d", + pSyncNode->vgId, syncUtilState2String(pSyncNode->state), pSyncNode->pRaftStore->currentTerm, + pSyncNode->commitIndex, logBeginIndex, logLastIndex, snapshot.lastApplyIndex, pSyncNode->pRaftCfg->isStandBy, + pSyncNode->replicaNum, pSyncNode->pRaftCfg->lastConfigIndex, pSyncNode->changing, pSyncNode->restoreFinish); + + /* + snprintf(s, len, + "syncNode: vgId:%d, term:%lu, commit:%ld, state:%d %s, standby:%d, " + "lc:%lu, " + "lc-user:%lu, " + "ems:%d, replica-num:%d, restore:%d, changing:%d", + pSyncNode->vgId, pSyncNode->pRaftStore->currentTerm, pSyncNode->commitIndex, pSyncNode->state, + syncUtilState2String(pSyncNode->state), pSyncNode->pRaftCfg->isStandBy, pSyncNode->electTimerLogicClock, + pSyncNode->electTimerLogicClockUser, pSyncNode->electTimerMS, pSyncNode->replicaNum, + pSyncNode->restoreFinish, pSyncNode->changing); + */ + return s; }