From 361c21a35caa2ef56d4b258f6cd8c6e2da5abaae Mon Sep 17 00:00:00 2001 From: Shengliang Guan Date: Fri, 8 Jul 2022 17:27:06 +0800 Subject: [PATCH] refactor: adjust logs --- include/libs/wal/wal.h | 44 ++++------------------ source/dnode/mnode/impl/inc/mndInt.h | 3 -- source/libs/sync/src/syncMain.c | 24 ++++++------ source/libs/transport/src/transCli.c | 2 +- source/libs/transport/src/transSvr.c | 5 +-- source/libs/wal/src/walRead.c | 55 ++++++++++++++++------------ source/libs/wal/src/walWrite.c | 3 +- 7 files changed, 57 insertions(+), 79 deletions(-) diff --git a/include/libs/wal/wal.h b/include/libs/wal/wal.h index 43792b5415..1556c72a56 100644 --- a/include/libs/wal/wal.h +++ b/include/libs/wal/wal.h @@ -24,42 +24,14 @@ extern "C" { #endif -#define wFatal(...) \ - { \ - if (wDebugFlag & DEBUG_FATAL) { \ - taosPrintLog("WAL FATAL ", DEBUG_FATAL, 255, __VA_ARGS__); \ - } \ - } -#define wError(...) \ - { \ - if (wDebugFlag & DEBUG_ERROR) { \ - taosPrintLog("WAL ERROR ", DEBUG_ERROR, 255, __VA_ARGS__); \ - } \ - } -#define wWarn(...) \ - { \ - if (wDebugFlag & DEBUG_WARN) { \ - taosPrintLog("WAL WARN ", DEBUG_WARN, 255, __VA_ARGS__); \ - } \ - } -#define wInfo(...) \ - { \ - if (wDebugFlag & DEBUG_INFO) { \ - taosPrintLog("WAL ", DEBUG_INFO, 255, __VA_ARGS__); \ - } \ - } -#define wDebug(...) \ - { \ - if (wDebugFlag & DEBUG_DEBUG) { \ - taosPrintLog("WAL ", DEBUG_DEBUG, wDebugFlag, __VA_ARGS__); \ - } \ - } -#define wTrace(...) \ - { \ - if (wDebugFlag & DEBUG_TRACE) { \ - taosPrintLog("WAL ", DEBUG_TRACE, wDebugFlag, __VA_ARGS__); \ - } \ - } +// clang-format off +#define wFatal(...) { if (wDebugFlag & DEBUG_FATAL) { taosPrintLog("WAL FATAL ", DEBUG_FATAL, 255, __VA_ARGS__); }} +#define wError(...) { if (wDebugFlag & DEBUG_ERROR) { taosPrintLog("WAL ERROR ", DEBUG_ERROR, 255, __VA_ARGS__); }} +#define wWarn(...) { if (wDebugFlag & DEBUG_WARN) { taosPrintLog("WAL WARN ", DEBUG_WARN, 255, __VA_ARGS__); }} +#define wInfo(...) { if (wDebugFlag & DEBUG_INFO) { taosPrintLog("WAL ", DEBUG_INFO, 255, __VA_ARGS__); }} +#define wDebug(...) { if (wDebugFlag & DEBUG_DEBUG) { taosPrintLog("WAL ", DEBUG_DEBUG, wDebugFlag, __VA_ARGS__); }} +#define wTrace(...) { if (wDebugFlag & DEBUG_TRACE) { taosPrintLog("WAL ", DEBUG_TRACE, wDebugFlag, __VA_ARGS__); }} +// clang-format on #define WAL_PROTO_VER 0 #define WAL_NOSUFFIX_LEN 20 diff --git a/source/dnode/mnode/impl/inc/mndInt.h b/source/dnode/mnode/impl/inc/mndInt.h index 14867ff693..b94c60c4ab 100644 --- a/source/dnode/mnode/impl/inc/mndInt.h +++ b/source/dnode/mnode/impl/inc/mndInt.h @@ -34,8 +34,6 @@ extern "C" { #endif // clang-format off - - #define mFatal(...) { if (mDebugFlag & DEBUG_FATAL) { taosPrintLog("MND FATAL ", DEBUG_FATAL, 255, __VA_ARGS__); }} #define mError(...) { if (mDebugFlag & DEBUG_ERROR) { taosPrintLog("MND ERROR ", DEBUG_ERROR, 255, __VA_ARGS__); }} #define mWarn(...) { if (mDebugFlag & DEBUG_WARN) { taosPrintLog("MND WARN ", DEBUG_WARN, 255, __VA_ARGS__); }} @@ -49,7 +47,6 @@ extern "C" { #define mGInfo(param, ...) { char buf[40] = {0}; TRACE_TO_STR(trace, buf); mInfo (param ", gtid:%s", __VA_ARGS__, buf);} #define mGDebug(param, ...) { char buf[40] = {0}; TRACE_TO_STR(trace, buf); mDebug(param ", gtid:%s", __VA_ARGS__, buf);} #define mGTrace(param, ...) { char buf[40] = {0}; TRACE_TO_STR(trace, buf); mTrace(param ", gtid:%s", __VA_ARGS__, buf);} - // clang-format on #define SYSTABLE_SCH_TABLE_NAME_LEN ((TSDB_TABLE_NAME_LEN - 1) + VARSTR_HEADER_SIZE) diff --git a/source/libs/sync/src/syncMain.c b/source/libs/sync/src/syncMain.c index 7fa13c9dc8..628868bb6b 100644 --- a/source/libs/sync/src/syncMain.c +++ b/source/libs/sync/src/syncMain.c @@ -1409,7 +1409,7 @@ cJSON* syncNode2Json(const SSyncNode* pSyncNode) { // tla+ log vars cJSON_AddItemToObject(pRoot, "pLogStore", logStore2Json(pSyncNode->pLogStore)); - snprintf(u64buf, sizeof(u64buf), "%" PRId64 "", pSyncNode->commitIndex); + snprintf(u64buf, sizeof(u64buf), "%" PRId64, pSyncNode->commitIndex); cJSON_AddStringToObject(pRoot, "commitIndex", u64buf); // timer ms init @@ -1421,39 +1421,39 @@ cJSON* syncNode2Json(const SSyncNode* pSyncNode) { snprintf(u64buf, sizeof(u64buf), "%p", pSyncNode->pPingTimer); cJSON_AddStringToObject(pRoot, "pPingTimer", u64buf); cJSON_AddNumberToObject(pRoot, "pingTimerMS", pSyncNode->pingTimerMS); - snprintf(u64buf, sizeof(u64buf), "%" PRIu64 "", pSyncNode->pingTimerLogicClock); + snprintf(u64buf, sizeof(u64buf), "%" PRIu64, pSyncNode->pingTimerLogicClock); cJSON_AddStringToObject(pRoot, "pingTimerLogicClock", u64buf); - snprintf(u64buf, sizeof(u64buf), "%" PRIu64 "", pSyncNode->pingTimerLogicClockUser); + snprintf(u64buf, sizeof(u64buf), "%" PRIu64, pSyncNode->pingTimerLogicClockUser); cJSON_AddStringToObject(pRoot, "pingTimerLogicClockUser", u64buf); snprintf(u64buf, sizeof(u64buf), "%p", pSyncNode->FpPingTimerCB); cJSON_AddStringToObject(pRoot, "FpPingTimerCB", u64buf); - snprintf(u64buf, sizeof(u64buf), "%" PRIu64 "", pSyncNode->pingTimerCounter); + snprintf(u64buf, sizeof(u64buf), "%" PRIu64, pSyncNode->pingTimerCounter); cJSON_AddStringToObject(pRoot, "pingTimerCounter", u64buf); // elect timer snprintf(u64buf, sizeof(u64buf), "%p", pSyncNode->pElectTimer); cJSON_AddStringToObject(pRoot, "pElectTimer", u64buf); cJSON_AddNumberToObject(pRoot, "electTimerMS", pSyncNode->electTimerMS); - snprintf(u64buf, sizeof(u64buf), "%" PRIu64 "", pSyncNode->electTimerLogicClock); + snprintf(u64buf, sizeof(u64buf), "%" PRIu64, pSyncNode->electTimerLogicClock); cJSON_AddStringToObject(pRoot, "electTimerLogicClock", u64buf); - snprintf(u64buf, sizeof(u64buf), "%" PRIu64 "", pSyncNode->electTimerLogicClockUser); + snprintf(u64buf, sizeof(u64buf), "%" PRIu64, pSyncNode->electTimerLogicClockUser); cJSON_AddStringToObject(pRoot, "electTimerLogicClockUser", u64buf); snprintf(u64buf, sizeof(u64buf), "%p", pSyncNode->FpElectTimerCB); cJSON_AddStringToObject(pRoot, "FpElectTimerCB", u64buf); - snprintf(u64buf, sizeof(u64buf), "%" PRIu64 "", pSyncNode->electTimerCounter); + snprintf(u64buf, sizeof(u64buf), "%" PRIu64, pSyncNode->electTimerCounter); cJSON_AddStringToObject(pRoot, "electTimerCounter", u64buf); // heartbeat timer snprintf(u64buf, sizeof(u64buf), "%p", pSyncNode->pHeartbeatTimer); cJSON_AddStringToObject(pRoot, "pHeartbeatTimer", u64buf); cJSON_AddNumberToObject(pRoot, "heartbeatTimerMS", pSyncNode->heartbeatTimerMS); - snprintf(u64buf, sizeof(u64buf), "%" PRIu64 "", pSyncNode->heartbeatTimerLogicClock); + snprintf(u64buf, sizeof(u64buf), "%" PRIu64, pSyncNode->heartbeatTimerLogicClock); cJSON_AddStringToObject(pRoot, "heartbeatTimerLogicClock", u64buf); - snprintf(u64buf, sizeof(u64buf), "%" PRIu64 "", pSyncNode->heartbeatTimerLogicClockUser); + snprintf(u64buf, sizeof(u64buf), "%" PRIu64, pSyncNode->heartbeatTimerLogicClockUser); cJSON_AddStringToObject(pRoot, "heartbeatTimerLogicClockUser", u64buf); snprintf(u64buf, sizeof(u64buf), "%p", pSyncNode->FpHeartbeatTimerCB); cJSON_AddStringToObject(pRoot, "FpHeartbeatTimerCB", u64buf); - snprintf(u64buf, sizeof(u64buf), "%" PRIu64 "", pSyncNode->heartbeatTimerCounter); + snprintf(u64buf, sizeof(u64buf), "%" PRIu64, pSyncNode->heartbeatTimerCounter); cJSON_AddStringToObject(pRoot, "heartbeatTimerCounter", u64buf); // callback @@ -2269,7 +2269,7 @@ static void syncNodeEqPingTimer(void* param, void* tmrId) { } } else { - sTrace("==syncNodeEqPingTimer== pingTimerLogicClock:%" PRIu64 ", pingTimerLogicClockUser:%" PRIu64 "", + sTrace("==syncNodeEqPingTimer== pingTimerLogicClock:%" PRIu64 ", pingTimerLogicClockUser:%" PRIu64, pSyncNode->pingTimerLogicClock, pSyncNode->pingTimerLogicClockUser); } } @@ -2304,7 +2304,7 @@ static void syncNodeEqElectTimer(void* param, void* tmrId) { sError("sync env is stop, syncNodeEqElectTimer"); } } else { - sTrace("==syncNodeEqElectTimer== electTimerLogicClock:%" PRIu64 ", electTimerLogicClockUser:%" PRIu64 "", + sTrace("==syncNodeEqElectTimer== electTimerLogicClock:%" PRIu64 ", electTimerLogicClockUser:%" PRIu64, pSyncNode->electTimerLogicClock, pSyncNode->electTimerLogicClockUser); } } diff --git a/source/libs/transport/src/transCli.c b/source/libs/transport/src/transCli.c index abeecd143e..0600b1130d 100644 --- a/source/libs/transport/src/transCli.c +++ b/source/libs/transport/src/transCli.c @@ -910,7 +910,7 @@ void* transInitClient(uint32_t ip, uint32_t port, char* label, int numOfThreads, int err = taosThreadCreate(&pThrd->thread, NULL, cliWorkThread, (void*)(pThrd)); if (err == 0) { - tDebug("success to create tranport-cli thread %d", i); + tDebug("success to create tranport-cli thread:%d", i); } cli->pThreadObj[i] = pThrd; } diff --git a/source/libs/transport/src/transSvr.c b/source/libs/transport/src/transSvr.c index 2624c252a2..9adbfdf49a 100644 --- a/source/libs/transport/src/transSvr.c +++ b/source/libs/transport/src/transSvr.c @@ -892,11 +892,10 @@ void* transInitServer(uint32_t ip, uint32_t port, char* label, int numOfThreads, } int err = taosThreadCreate(&(thrd->thread), NULL, transWorkerThread, (void*)(thrd)); if (err == 0) { - tDebug("sucess to create worker-thread %d", i); - // printf("thread %d create\n", i); + tDebug("success to create worker-thread:%d", i); } else { // TODO: clear all other resource later - tError("failed to create worker-thread %d", i); + tError("failed to create worker-thread:%d", i); goto End; } } diff --git a/source/libs/wal/src/walRead.c b/source/libs/wal/src/walRead.c index 5d28e7288e..07fd10bd61 100644 --- a/source/libs/wal/src/walRead.c +++ b/source/libs/wal/src/walRead.c @@ -94,17 +94,19 @@ static int64_t walReadSeekFilePos(SWalReader *pRead, int64_t fileFirstVer, int64 ret = taosLSeekFile(pIdxTFile, offset, SEEK_SET); if (ret < 0) { terrno = TAOS_SYSTEM_ERROR(errno); - wError("failed to seek idx file, ver:%" PRId64 ", pos:%" PRId64 ", since %s", ver, offset, terrstr()); + wError("vgId:%d, failed to seek idx file, ver:%" PRId64 ", pos:%" PRId64 ", since %s", pRead->pWal->cfg.vgId, ver, + offset, terrstr()); return -1; } SWalIdxEntry entry = {0}; if ((ret = taosReadFile(pIdxTFile, &entry, sizeof(SWalIdxEntry))) != sizeof(SWalIdxEntry)) { if (ret < 0) { terrno = TAOS_SYSTEM_ERROR(errno); - wError("failed to read idx file, since %s", terrstr()); + wError("vgId:%d, failed to read idx file, since %s", pRead->pWal->cfg.vgId, terrstr()); } else { terrno = TSDB_CODE_WAL_FILE_CORRUPTED; - wError("read idx file incompletely, read bytes %" PRId64 ", bytes should be %" PRIu64, ret, sizeof(SWalIdxEntry)); + wError("vgId:%d, read idx file incompletely, read bytes %" PRId64 ", bytes should be %" PRIu64, + pRead->pWal->cfg.vgId, ret, sizeof(SWalIdxEntry)); } return -1; } @@ -113,7 +115,8 @@ static int64_t walReadSeekFilePos(SWalReader *pRead, int64_t fileFirstVer, int64 ret = taosLSeekFile(pLogTFile, entry.offset, SEEK_SET); if (ret < 0) { terrno = TAOS_SYSTEM_ERROR(errno); - wError("failed to seek log file, ver:%" PRId64 ", pos:%" PRId64 ", since %s", ver, entry.offset, terrstr()); + wError("vgId:%d, failed to seek log file, ver:%" PRId64 ", pos:%" PRId64 ", since %s", pRead->pWal->cfg.vgId, ver, + entry.offset, terrstr()); return -1; } return ret; @@ -129,7 +132,7 @@ static int32_t walReadChangeFile(SWalReader *pRead, int64_t fileFirstVer) { TdFilePtr pLogTFile = taosOpenFile(fnameStr, TD_FILE_READ); if (pLogTFile == NULL) { terrno = TAOS_SYSTEM_ERROR(errno); - wError("cannot open file %s, since %s", fnameStr, terrstr()); + wError("vgId:%d, cannot open file %s, since %s", pRead->pWal->cfg.vgId, fnameStr, terrstr()); return -1; } @@ -139,7 +142,7 @@ static int32_t walReadChangeFile(SWalReader *pRead, int64_t fileFirstVer) { TdFilePtr pIdxTFile = taosOpenFile(fnameStr, TD_FILE_READ); if (pIdxTFile == NULL) { terrno = TAOS_SYSTEM_ERROR(errno); - wError("cannot open file %s, since %s", fnameStr, terrstr()); + wError("vgId:%d, cannot open file %s, since %s", pRead->pWal->cfg.vgId, fnameStr, terrstr()); return -1; } @@ -153,8 +156,8 @@ static int32_t walReadSeekVer(SWalReader *pRead, int64_t ver) { return 0; } if (ver > pWal->vers.lastVer || ver < pWal->vers.firstVer) { - wError("invalid version:%" PRId64 ", first ver:%" PRId64 ", last ver:%" PRId64, ver, pWal->vers.firstVer, - pWal->vers.lastVer); + wError("vgId:$d, invalid version:%" PRId64 ", first ver:%" PRId64 ", last ver:%" PRId64, pRead->pWal->cfg.vgId, ver, + pWal->vers.firstVer, pWal->vers.lastVer); terrno = TSDB_CODE_WAL_LOG_NOT_EXIST; return -1; } @@ -221,11 +224,11 @@ static int32_t walFetchBodyNew(SWalReader *pRead) { if (pReadHead->bodyLen != taosReadFile(pRead->pLogFile, pReadHead->body, pReadHead->bodyLen)) { if (pReadHead->bodyLen < 0) { terrno = TAOS_SYSTEM_ERROR(errno); - wError("wal fetch body error: %" PRId64 ", read request version:%" PRId64 ", since %s", - pRead->pHead->head.version, ver, tstrerror(terrno)); + wError("vgId:%d, wal fetch body error: %" PRId64 ", read request version:%" PRId64 ", since %s", + pRead->pWal->cfg.vgId, pRead->pHead->head.version, ver, tstrerror(terrno)); } else { - wError("wal fetch body error: %" PRId64 ", read request version:%" PRId64 ", since file corrupted", - pRead->pHead->head.version, ver); + wError("vgId:%d, wal fetch body error: %" PRId64 ", read request version:%" PRId64 ", since file corrupted", + pRead->pWal->cfg.vgId, pRead->pHead->head.version, ver); terrno = TSDB_CODE_WAL_FILE_CORRUPTED; } pRead->curVersion = -1; @@ -234,7 +237,8 @@ static int32_t walFetchBodyNew(SWalReader *pRead) { } if (pReadHead->version != ver) { - wError("wal fetch body error: %" PRId64 ", read request version:%" PRId64 "", pRead->pHead->head.version, ver); + wError("vgId:%d, wal fetch body error: %" PRId64 ", read request version:%" PRId64, pRead->pWal->cfg.vgId, + pRead->pHead->head.version, ver); pRead->curVersion = -1; terrno = TSDB_CODE_WAL_FILE_CORRUPTED; ASSERT(0); @@ -242,7 +246,7 @@ static int32_t walFetchBodyNew(SWalReader *pRead) { } if (walValidBodyCksum(pRead->pHead) != 0) { - wError("wal fetch body error: % " PRId64 ", since body checksum not passed", ver); + wError("vgId:%d, wal fetch body error: % " PRId64 ", since body checksum not passed", pRead->pWal->cfg.vgId, ver); pRead->curVersion = -1; terrno = TSDB_CODE_WAL_FILE_CORRUPTED; ASSERT(0); @@ -293,7 +297,8 @@ int32_t walFetchHead(SWalReader *pRead, int64_t ver, SWalCkHead *pHead) { code = walValidHeadCksum(pHead); if (code != 0) { - wError("unexpected wal log version:%" PRId64 ", since head checksum not passed", ver); + wError("vgId:%d, unexpected wal log version:%" PRId64 ", since head checksum not passed", pRead->pWal->cfg.vgId, + ver); terrno = TSDB_CODE_WAL_FILE_CORRUPTED; return -1; } @@ -339,14 +344,15 @@ int32_t walFetchBody(SWalReader *pRead, SWalCkHead **ppHead) { } if (pReadHead->version != ver) { - wError("wal fetch body error: %" PRId64 ", read request version:%" PRId64 "", pRead->pHead->head.version, ver); + wError("vgId:%d, wal fetch body error: %" PRId64 ", read request version:%" PRId64, pRead->pWal->cfg.vgId, + pRead->pHead->head.version, ver); pRead->curVersion = -1; terrno = TSDB_CODE_WAL_FILE_CORRUPTED; return -1; } if (walValidBodyCksum(*ppHead) != 0) { - wError("wal fetch body error: % " PRId64 ", since body checksum not passed", ver); + wError("vgId:%d, wal fetch body error: % " PRId64 ", since body checksum not passed", pRead->pWal->cfg.vgId, ver); pRead->curVersion = -1; terrno = TSDB_CODE_WAL_FILE_CORRUPTED; return -1; @@ -383,14 +389,14 @@ int32_t walReadVer(SWalReader *pRead, int64_t ver) { // TODO: check wal life if (pRead->curVersion != ver) { if (walReadSeekVer(pRead, ver) < 0) { - wError("unexpected wal log version:%" PRId64 ", since %s", ver, terrstr()); + wError("vgId:%d, unexpected wal log version:%" PRId64 ", since %s", pRead->pWal->cfg.vgId, ver, terrstr()); return -1; } } if (ver > pRead->pWal->vers.lastVer || ver < pRead->pWal->vers.firstVer) { - wError("invalid version:%" PRId64 ", first ver:%" PRId64 ", last ver:%" PRId64, ver, pRead->pWal->vers.firstVer, - pRead->pWal->vers.lastVer); + wError("vgId:%d, invalid version:%" PRId64 ", first ver:%" PRId64 ", last ver:%" PRId64, pRead->pWal->cfg.vgId, ver, + pRead->pWal->vers.firstVer, pRead->pWal->vers.lastVer); terrno = TSDB_CODE_WAL_LOG_NOT_EXIST; return -1; } @@ -410,7 +416,8 @@ int32_t walReadVer(SWalReader *pRead, int64_t ver) { code = walValidHeadCksum(pRead->pHead); if (code != 0) { - wError("unexpected wal log version:%" PRId64 ", since head checksum not passed", ver); + wError("vgId:%d, unexpected wal log version:%" PRId64 ", since head checksum not passed", pRead->pWal->cfg.vgId, + ver); terrno = TSDB_CODE_WAL_FILE_CORRUPTED; return -1; } @@ -437,7 +444,8 @@ int32_t walReadVer(SWalReader *pRead, int64_t ver) { } if (pRead->pHead->head.version != ver) { - wError("unexpected wal log version:%" PRId64 ", read request version:%" PRId64 "", pRead->pHead->head.version, ver); + wError("vgId:%d, unexpected wal log version:%" PRId64 ", read request version:%" PRId64, pRead->pWal->cfg.vgId, + pRead->pHead->head.version, ver); pRead->curVersion = -1; terrno = TSDB_CODE_WAL_FILE_CORRUPTED; return -1; @@ -445,7 +453,8 @@ int32_t walReadVer(SWalReader *pRead, int64_t ver) { code = walValidBodyCksum(pRead->pHead); if (code != 0) { - wError("unexpected wal log version:%" PRId64 ", since body checksum not passed", ver); + wError("vgId:%d, unexpected wal log version:%" PRId64 ", since body checksum not passed", pRead->pWal->cfg.vgId, + ver); pRead->curVersion = -1; terrno = TSDB_CODE_WAL_FILE_CORRUPTED; return -1; diff --git a/source/libs/wal/src/walWrite.c b/source/libs/wal/src/walWrite.c index 792f37150c..a09f7d8075 100644 --- a/source/libs/wal/src/walWrite.c +++ b/source/libs/wal/src/walWrite.c @@ -318,7 +318,8 @@ int walRoll(SWal *pWal) { static int walWriteIndex(SWal *pWal, int64_t ver, int64_t offset) { SWalIdxEntry entry = {.ver = ver, .offset = offset}; int64_t idxOffset = taosLSeekFile(pWal->pWriteIdxTFile, 0, SEEK_END); - wDebug("write index, ver:%" PRId64 ", offset:%" PRId64 ", at %" PRId64, ver, offset, idxOffset); + wDebug("vgId:%d, write index, ver:%" PRId64 ", offset:%" PRId64 ", at %" PRId64, pWal->cfg.vgId, ver, offset, + idxOffset); int64_t size = taosWriteFile(pWal->pWriteIdxTFile, &entry, sizeof(SWalIdxEntry)); if (size != sizeof(SWalIdxEntry)) { terrno = TAOS_SYSTEM_ERROR(errno); -- GitLab