From 198e18c348fd49e0f827e851ef37dd50b7045bdb Mon Sep 17 00:00:00 2001 From: Minghao Li Date: Tue, 29 Nov 2022 14:58:47 +0800 Subject: [PATCH] refactor(sync): add trace log for cache hit, cache miss --- include/libs/sync/sync.h | 5 ++++- source/libs/sync/src/syncAppendEntries.c | 2 ++ source/libs/sync/src/syncCommit.c | 2 ++ source/libs/sync/src/syncMain.c | 6 ++++++ source/libs/sync/src/syncRaftLog.c | 3 +++ source/libs/sync/src/syncReplication.c | 2 ++ source/libs/sync/src/syncUtil.c | 13 ++++++++----- 7 files changed, 27 insertions(+), 6 deletions(-) diff --git a/include/libs/sync/sync.h b/include/libs/sync/sync.h index b8a4726be0..b6d0aecfd1 100644 --- a/include/libs/sync/sync.h +++ b/include/libs/sync/sync.h @@ -162,7 +162,10 @@ typedef struct SSyncFSM { // SWal implements it typedef struct SSyncLogStore { SLRUCache* pCache; - void* data; + int32_t cacheHit; + int32_t cacheMiss; + + void* data; int32_t (*syncLogUpdateCommitIndex)(struct SSyncLogStore* pLogStore, SyncIndex index); SyncIndex (*syncLogCommitIndex)(struct SSyncLogStore* pLogStore); diff --git a/source/libs/sync/src/syncAppendEntries.c b/source/libs/sync/src/syncAppendEntries.c index df2ccee546..fbf096589d 100644 --- a/source/libs/sync/src/syncAppendEntries.c +++ b/source/libs/sync/src/syncAppendEntries.c @@ -205,9 +205,11 @@ int32_t syncNodeOnAppendEntries(SSyncNode* ths, const SRpcMsg* pRpcMsg) { pLocalEntry = (SSyncRaftEntry*)taosLRUCacheValue(pCache, hLocal); code = 0; + ths->pLogStore->cacheHit++; sNTrace(ths, "hit cache index:%" PRId64 ", bytes:%u, %p", appendIndex, pLocalEntry->bytes, pLocalEntry); } else { + ths->pLogStore->cacheMiss++; sNTrace(ths, "miss cache index:%" PRId64, appendIndex); code = ths->pLogStore->syncLogGetEntry(ths->pLogStore, appendIndex, &pLocalEntry); diff --git a/source/libs/sync/src/syncCommit.c b/source/libs/sync/src/syncCommit.c index dbe72bea7a..7d77361b3c 100644 --- a/source/libs/sync/src/syncCommit.c +++ b/source/libs/sync/src/syncCommit.c @@ -117,9 +117,11 @@ void syncMaybeAdvanceCommitIndex(SSyncNode* pSyncNode) { if (h) { pEntry = (SSyncRaftEntry*)taosLRUCacheValue(pCache, h); + pSyncNode->pLogStore->cacheHit++; sNTrace(pSyncNode, "hit cache index:%" PRId64 ", bytes:%u, %p", index, pEntry->bytes, pEntry); } else { + pSyncNode->pLogStore->cacheMiss++; sNTrace(pSyncNode, "miss cache index:%" PRId64, index); int32_t code = pSyncNode->pLogStore->syncLogGetEntry(pSyncNode->pLogStore, index, &pEntry); diff --git a/source/libs/sync/src/syncMain.c b/source/libs/sync/src/syncMain.c index 7fc8ba434a..62eba3208e 100644 --- a/source/libs/sync/src/syncMain.c +++ b/source/libs/sync/src/syncMain.c @@ -410,9 +410,11 @@ bool syncIsReadyForRead(int64_t rid) { pEntry = (SSyncRaftEntry*)taosLRUCacheValue(pCache, h); code = 0; + pSyncNode->pLogStore->cacheHit++; sNTrace(pSyncNode, "hit cache index:%" PRId64 ", bytes:%u, %p", lastIndex, pEntry->bytes, pEntry); } else { + pSyncNode->pLogStore->cacheMiss++; sNTrace(pSyncNode, "miss cache index:%" PRId64, lastIndex); code = pSyncNode->pLogStore->syncLogGetEntry(pSyncNode->pLogStore, lastIndex, &pEntry); @@ -1850,9 +1852,11 @@ SyncTerm syncNodeGetPreTerm(SSyncNode* pSyncNode, SyncIndex index) { pPreEntry = (SSyncRaftEntry*)taosLRUCacheValue(pCache, h); code = 0; + pSyncNode->pLogStore->cacheHit++; sNTrace(pSyncNode, "hit cache index:%" PRId64 ", bytes:%u, %p", preIndex, pPreEntry->bytes, pPreEntry); } else { + pSyncNode->pLogStore->cacheMiss++; sNTrace(pSyncNode, "miss cache index:%" PRId64, preIndex); code = pSyncNode->pLogStore->syncLogGetEntry(pSyncNode->pLogStore, preIndex, &pPreEntry); @@ -2534,9 +2538,11 @@ int32_t syncNodeDoCommit(SSyncNode* ths, SyncIndex beginIndex, SyncIndex endInde if (h) { pEntry = (SSyncRaftEntry*)taosLRUCacheValue(pCache, h); + ths->pLogStore->cacheHit++; sNTrace(ths, "hit cache index:%" PRId64 ", bytes:%u, %p", i, pEntry->bytes, pEntry); } else { + ths->pLogStore->cacheMiss++; sNTrace(ths, "miss cache index:%" PRId64, i); code = ths->pLogStore->syncLogGetEntry(ths->pLogStore, i, &pEntry); diff --git a/source/libs/sync/src/syncRaftLog.c b/source/libs/sync/src/syncRaftLog.c index 2f824b6b3b..60fc3a9bf7 100644 --- a/source/libs/sync/src/syncRaftLog.c +++ b/source/libs/sync/src/syncRaftLog.c @@ -45,6 +45,9 @@ SSyncLogStore* logStoreCreate(SSyncNode* pSyncNode) { return NULL; } + pLogStore->cacheHit = 0; + pLogStore->cacheMiss = 0; + taosLRUCacheSetStrictCapacity(pLogStore->pCache, false); pLogStore->data = taosMemoryMalloc(sizeof(SSyncLogStoreData)); diff --git a/source/libs/sync/src/syncReplication.c b/source/libs/sync/src/syncReplication.c index 7d2a8b46fd..23d83b14e6 100644 --- a/source/libs/sync/src/syncReplication.c +++ b/source/libs/sync/src/syncReplication.c @@ -80,9 +80,11 @@ int32_t syncNodeReplicateOne(SSyncNode* pSyncNode, SRaftId* pDestId, bool snapsh pEntry = (SSyncRaftEntry*)taosLRUCacheValue(pCache, h); code = 0; + pSyncNode->pLogStore->cacheHit++; sNTrace(pSyncNode, "hit cache index:%" PRId64 ", bytes:%u, %p", nextIndex, pEntry->bytes, pEntry); } else { + pSyncNode->pLogStore->cacheMiss++; sNTrace(pSyncNode, "miss cache index:%" PRId64, nextIndex); code = pSyncNode->pLogStore->syncLogGetEntry(pSyncNode->pLogStore, nextIndex, &pEntry); diff --git a/source/libs/sync/src/syncUtil.c b/source/libs/sync/src/syncUtil.c index abf6b21baa..c022a3e75b 100644 --- a/source/libs/sync/src/syncUtil.c +++ b/source/libs/sync/src/syncUtil.c @@ -242,6 +242,9 @@ void syncPrintNodeLog(const char* flags, ELogLevel level, int32_t dflag, SSyncNo logBeginIndex = pNode->pLogStore->syncLogBeginIndex(pNode->pLogStore); } + int32_t cacheHit = pNode->pLogStore->cacheHit; + int32_t cacheMiss = pNode->pLogStore->cacheMiss; + char cfgStr[1024]; if (pNode->pRaftCfg != NULL) { syncCfg2SimpleStr(&(pNode->pRaftCfg->cfg), cfgStr, sizeof(cfgStr)); @@ -280,13 +283,13 @@ void syncPrintNodeLog(const char* flags, ELogLevel level, int32_t dflag, SSyncNo "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", + ", snap-tm:%" PRIu64 ", elt-num:%d, bl-num:%d, cc-num:%d, hit:%d, mis:%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); + pNode->configChangeNum, cacheHit, cacheMiss, aqItems, pNode->snapshottingIndex, pNode->replicaNum, + pNode->pRaftCfg->lastConfigIndex, pNode->changing, pNode->restoreFinish, quorum, pNode->electTimerLogicClock, + pNode->heartbeatTimerLogicClockUser, peerStr, cfgStr, hbTimeStr, hbrTimeStr); } } -- GitLab