From 8f55e007f4f3a8f98309b7fa9df9f28666f015ca Mon Sep 17 00:00:00 2001 From: Minghao Li Date: Mon, 14 Nov 2022 16:23:52 +0800 Subject: [PATCH] refactor(sync): add trace log --- source/libs/sync/src/syncRaftLog.c | 18 +++++++++++++++--- 1 file changed, 15 insertions(+), 3 deletions(-) diff --git a/source/libs/sync/src/syncRaftLog.c b/source/libs/sync/src/syncRaftLog.c index bc07781e5c..21f301308e 100644 --- a/source/libs/sync/src/syncRaftLog.c +++ b/source/libs/sync/src/syncRaftLog.c @@ -239,12 +239,12 @@ int32_t raftLogGetEntry(struct SSyncLogStore* pLogStore, SyncIndex index, SSyncR return -1; } + int64_t ts1 = taosGetTimestampMs(); taosThreadMutexLock(&(pData->mutex)); - int64_t tsBegin = taosGetTimestampMs(); + int64_t ts2 = taosGetTimestampMs(); code = walReadVer(pWalHandle, index); - int64_t tsEnd = taosGetTimestampMs(); - int64_t tsElapsed = tsEnd - tsBegin; + int64_t ts3 = taosGetTimestampMs(); // code = walReadVerCached(pWalHandle, index); if (code != 0) { @@ -289,6 +289,18 @@ int32_t raftLogGetEntry(struct SSyncLogStore* pLogStore, SyncIndex index, SSyncR */ taosThreadMutexUnlock(&(pData->mutex)); + int64_t ts4 = taosGetTimestampMs(); + + int64_t tsElapsed = ts4 - ts1; + int64_t tsElapsedLock = ts2 - ts1; + int64_t tsElapsedRead = ts3 - ts2; + int64_t tsElapsedBuild = ts4 - ts3; + + sNTrace(pData->pSyncNode, + "read index:%" PRId64 ", elapsed:%" PRId64 ", elapsed-lock:%" PRId64 ", elapsed-read:%" PRId64 + ", elapsed-build:%" PRId64, + index, tsElapsed, tsElapsedLock, tsElapsedRead, tsElapsedBuild); + return code; }