diff --git a/src/common/src/tglobal.c b/src/common/src/tglobal.c index 75c8f93a82f1c71ff7d356500739d95cc3658444..3bc1e4d0cc1c4de3365a1324001704f53584ab3b 100644 --- a/src/common/src/tglobal.c +++ b/src/common/src/tglobal.c @@ -218,6 +218,8 @@ int32_t (*monitorStartSystemFp)() = NULL; void (*monitorStopSystemFp)() = NULL; void (*monitorExecuteSQLFp)(char *sql) = NULL; +char *qtypeStr[] = {"rpc", "fwd", "wal", "cq", "query"}; + static pthread_once_t tsInitGlobalCfgOnce = PTHREAD_ONCE_INIT; void taosSetAllDebugFlag() { diff --git a/src/dnode/src/dnodeVWrite.c b/src/dnode/src/dnodeVWrite.c index 9b7497d3ecd51a591b827ed3bb710411015538d4..e0345eb1f6f72c28a99b99546f2d0c2a96b8ed37 100644 --- a/src/dnode/src/dnodeVWrite.c +++ b/src/dnode/src/dnodeVWrite.c @@ -207,8 +207,8 @@ static void *dnodeProcessVWriteQueue(void *param) { bool forceFsync = false; for (int32_t i = 0; i < numOfMsgs; ++i) { taosGetQitem(pWorker->qall, &qtype, (void **)&pWrite); - dTrace("%p, msg:%p:%s will be processed in vwrite queue, qtype:%d version:%" PRIu64, pWrite->rpcAhandle, pWrite, - taosMsg[pWrite->pHead->msgType], qtype, pWrite->pHead->version); + dTrace("%p, msg:%p:%s will be processed in vwrite queue, qtype:%s hver:%" PRIu64, pWrite->rpcAhandle, pWrite, + taosMsg[pWrite->pHead->msgType], qtypeStr[qtype], pWrite->pHead->version); pWrite->code = vnodeProcessWrite(pVnode, pWrite->pHead, qtype, &pWrite->rspRet); if (pWrite->code <= 0) pWrite->processedCount = 1; diff --git a/src/inc/taosdef.h b/src/inc/taosdef.h index 6ee25673227f4a36caf8c01508a8c8078475bcd7..fa8af2c67e5dff0cbc0a66a4fca3bfa9f84cbe26 100644 --- a/src/inc/taosdef.h +++ b/src/inc/taosdef.h @@ -467,6 +467,8 @@ typedef enum { TSDB_CHECK_ITEM_MAX } ECheckItemType; +extern char *qtypeStr[]; + #ifdef __cplusplus } #endif diff --git a/src/sync/src/syncMain.c b/src/sync/src/syncMain.c index eee8af7bcd1cedc601ab823de5b542b7edcdb051..3d860f8bbb0225a830c4dd1b78115692a77b3198 100644 --- a/src/sync/src/syncMain.c +++ b/src/sync/src/syncMain.c @@ -1221,8 +1221,8 @@ static int32_t syncForwardToPeerImpl(SSyncNode *pNode, void *data, void *mhandle // always update version nodeVersion = pWalHead->version; - sDebug("vgId:%d, replica:%d nodeRole:%s qtype:%d ver:%" PRIu64, pNode->vgId, pNode->replica, syncRole[nodeRole], - qtype, pWalHead->version); + sDebug("vgId:%d, forward to peer, replica:%d role:%s qtype:%s hver:%" PRIu64, pNode->vgId, pNode->replica, + syncRole[nodeRole], qtypeStr[qtype], pWalHead->version); if (pNode->replica == 1 || nodeRole != TAOS_SYNC_ROLE_MASTER) return 0; diff --git a/src/sync/src/syncRestore.c b/src/sync/src/syncRestore.c index 9216567bc5e798f61da380c30c0409fe585353bc..b35388db35d14979e8d292384f407e64903362d4 100644 --- a/src/sync/src/syncRestore.c +++ b/src/sync/src/syncRestore.c @@ -153,7 +153,7 @@ static int syncRestoreWal(SSyncPeer *pPeer) { ret = taosReadMsg(pPeer->syncFd, pHead->cont, pHead->len); if (ret < 0) break; - sDebug("%s, restore a record, ver:%" PRIu64, pPeer->id, pHead->version); + sDebug("%s, restore a record, qtype:wal hver:%" PRIu64, pPeer->id, pHead->version); (*pNode->writeToCache)(pNode->ahandle, pHead, TAOS_QTYPE_WAL, NULL); } diff --git a/src/sync/src/syncRetrieve.c b/src/sync/src/syncRetrieve.c index 0fe189db7a5fa15fb05b2182acfac5dac1160cfe..d77587f2274918c230f5993f7fa7736da07469f9 100644 --- a/src/sync/src/syncRetrieve.c +++ b/src/sync/src/syncRetrieve.c @@ -256,7 +256,7 @@ static int syncRetrieveLastWal(SSyncPeer *pPeer, char *name, uint64_t fversion, } (void)lseek(sfd, offset, SEEK_SET); - sDebug("%s, retrieve last wal, offset:%" PRId64 " fversion:%" PRIu64, pPeer->id, offset, fversion); + sDebug("%s, retrieve last wal, offset:%" PRId64 " fver:%" PRIu64, pPeer->id, offset, fversion); while (1) { int wsize = syncReadOneWalRecord(sfd, pHead, pEvent); @@ -325,7 +325,7 @@ static int syncProcessLastWal(SSyncPeer *pPeer, char *wname, int64_t index) { // if all data up to fversion is read out, it is over if (pPeer->sversion >= fversion && fversion > 0) { code = 0; - sDebug("%s, data up to fversion:%" PRId64 " has been read out, bytes:%d", pPeer->id, fversion, bytes); + sDebug("%s, data up to fver:%" PRIu64 " has been read out, bytes:%d", pPeer->id, fversion, bytes); break; } diff --git a/src/vnode/src/vnodeMain.c b/src/vnode/src/vnodeMain.c index 4cdf9f898a7d6c2bffc51cf2b2bfc297e5db087a..f90b9701fe87298f6d16c25eab65b5ad87c1a120 100644 --- a/src/vnode/src/vnodeMain.c +++ b/src/vnode/src/vnodeMain.c @@ -577,10 +577,12 @@ static int vnodeProcessTsdbStatus(void *arg, int status) { if (status == TSDB_STATUS_COMMIT_START) { pVnode->fversion = pVnode->version; + vDebug("vgId:%d, start commit, fver:%" PRIu64 " vver:%" PRIu64, pVnode->vgId, pVnode->fversion, pVnode->version); return walRenew(pVnode->wal); } if (status == TSDB_STATUS_COMMIT_OVER) { + vDebug("vgId:%d, commit over, fver:%" PRIu64 " vver:%" PRIu64, pVnode->vgId, pVnode->fversion, pVnode->version); return vnodeSaveVersion(pVnode); } @@ -656,11 +658,12 @@ static int vnodeResetTsdb(SVnodeObj *pVnode) { static int vnodeNotifyFileSynced(void *ahandle, uint64_t fversion) { SVnodeObj *pVnode = ahandle; - vDebug("vgId:%d, data file is synced, fversion:%" PRId64, pVnode->vgId, fversion); pVnode->fversion = fversion; pVnode->version = fversion; vnodeSaveVersion(pVnode); + vDebug("vgId:%d, data file is synced, fver:%" PRIu64 " vver:%" PRIu64, pVnode->vgId, pVnode->fversion, + pVnode->version); return vnodeResetTsdb(pVnode); } diff --git a/src/vnode/src/vnodeVersion.c b/src/vnode/src/vnodeVersion.c index 51f9ac8f3ad17287141034e50fe6692b13c6c930..8f6360b4f98eac8f394f5078ed2b025cea4192b0 100644 --- a/src/vnode/src/vnodeVersion.c +++ b/src/vnode/src/vnodeVersion.c @@ -64,7 +64,7 @@ int32_t vnodeReadVersion(SVnodeObj *pVnode) { pVnode->version = (uint64_t)ver->valueint; terrno = TSDB_CODE_SUCCESS; - vInfo("vgId:%d, read %s successfully, version:%" PRIu64, pVnode->vgId, file, pVnode->version); + vInfo("vgId:%d, read %s successfully, fver:%" PRIu64, pVnode->vgId, file, pVnode->version); PARSE_VER_ERROR: if (content != NULL) free(content); @@ -98,6 +98,6 @@ int32_t vnodeSaveVersion(SVnodeObj *pVnode) { free(content); terrno = 0; - vInfo("vgId:%d, successed to write %s, version:%" PRIu64, pVnode->vgId, file, pVnode->fversion); + vInfo("vgId:%d, successed to write %s, fver:%" PRIu64, pVnode->vgId, file, pVnode->fversion); return TSDB_CODE_SUCCESS; } \ No newline at end of file diff --git a/src/vnode/src/vnodeWrite.c b/src/vnode/src/vnodeWrite.c index f42b359b26d8467cda65a9f04a70d3db2305f234..99594607ac0a19e31f438e0a02320ee189d55253 100644 --- a/src/vnode/src/vnodeWrite.c +++ b/src/vnode/src/vnodeWrite.c @@ -52,20 +52,24 @@ int32_t vnodeProcessWrite(void *vparam, void *wparam, int32_t qtype, void *rpara SRspRet * pRspRet = rparam; if (vnodeProcessWriteMsgFp[pHead->msgType] == NULL) { - vDebug("vgId:%d, msgType:%s not processed, no handle", pVnode->vgId, taosMsg[pHead->msgType]); + vError("vgId:%d, msg:%s not processed since no handle, qtype:%s hver:%" PRIu64, pVnode->vgId, + taosMsg[pHead->msgType], qtypeStr[qtype], pHead->version); return TSDB_CODE_VND_MSG_NOT_PROCESSED; } + vTrace("vgId:%d, msg:%s will be processed in vnode, qtype:%s hver:%" PRIu64 " vver:%" PRIu64, pVnode->vgId, + taosMsg[pHead->msgType], qtypeStr[qtype], pHead->version, pVnode->version); + if (pHead->version == 0) { // from client or CQ if (pVnode->status != TAOS_VN_STATUS_READY) { - vDebug("vgId:%d, msgType:%s not processed, vnode status is %d", pVnode->vgId, taosMsg[pHead->msgType], - pVnode->status); + vDebug("vgId:%d, msg:%s not processed since vstatus:%d, qtype:%s hver:%" PRIu64, pVnode->vgId, + taosMsg[pHead->msgType], pVnode->status, qtypeStr[qtype], pHead->version); return TSDB_CODE_APP_NOT_READY; // it may be in deleting or closing state } if (pVnode->role != TAOS_SYNC_ROLE_MASTER) { - vDebug("vgId:%d, msgType:%s not processed, replica:%d role:%s", pVnode->vgId, taosMsg[pHead->msgType], - pVnode->syncCfg.replica, syncRole[pVnode->role]); + vDebug("vgId:%d, msg:%s not processed since replica:%d role:%s, qtype:%s hver:%" PRIu64, pVnode->vgId, + taosMsg[pHead->msgType], pVnode->syncCfg.replica, syncRole[pVnode->role], qtypeStr[qtype], pHead->version); return TSDB_CODE_APP_NOT_READY; } diff --git a/src/wal/src/walWrite.c b/src/wal/src/walWrite.c index ecd0fd0ca05f890654fca079b4bec6dce3916454..9681f4b898d0661d25650067362be429854e8c94 100644 --- a/src/wal/src/walWrite.c +++ b/src/wal/src/walWrite.c @@ -99,8 +99,8 @@ int32_t walWrite(void *handle, SWalHead *pHead) { code = TAOS_SYSTEM_ERROR(errno); wError("vgId:%d, file:%s, failed to write since %s", pWal->vgId, pWal->name, strerror(errno)); } else { - wTrace("vgId:%d, fileId:%" PRId64 " fd:%d, write wal ver:%" PRId64 ", head ver:%" PRIu64 ", len:%d ", pWal->vgId, - pWal->fileId, pWal->fd, pWal->version, pHead->version, pHead->len); + wTrace("vgId:%d, write wal, fileId:%" PRId64 " fd:%d hver:%" PRId64 " wver:%" PRIu64 " len:%d", pWal->vgId, + pWal->fileId, pWal->fd, pHead->version, pWal->version, pHead->len); pWal->version = pHead->version; } @@ -261,7 +261,7 @@ static int32_t walRestoreWalFile(SWal *pWal, void *pVnode, FWalWrite writeFp, ch } if (!taosCheckChecksumWhole((uint8_t *)pHead, sizeof(SWalHead))) { - wError("vgId:%d, file:%s, wal head cksum is messed up, ver:%" PRIu64 " len:%d offset:%" PRId64, pWal->vgId, name, + wError("vgId:%d, file:%s, wal head cksum is messed up, hver:%" PRIu64 " len:%d offset:%" PRId64, pWal->vgId, name, pHead->version, pHead->len, offset); code = walSkipCorruptedRecord(pWal, pHead, fd, &offset); if (code != TSDB_CODE_SUCCESS) { @@ -297,8 +297,8 @@ static int32_t walRestoreWalFile(SWal *pWal, void *pVnode, FWalWrite writeFp, ch offset = offset + sizeof(SWalHead) + pHead->len; - wTrace("vgId:%d, fileId:%" PRId64 ", restore wal ver:%" PRIu64 ", head ver:%" PRIu64 " len:%d", pWal->vgId, fileId, - pWal->version, pHead->version, pHead->len); + wTrace("vgId:%d, restore wal, fileId:%" PRId64 " hver:%" PRIu64 " wver:%" PRIu64 " len:%d", pWal->vgId, + fileId, pHead->version, pWal->version, pHead->len); pWal->version = pHead->version; (*writeFp)(pVnode, pHead, TAOS_QTYPE_WAL, NULL);