xxq250
/
homework-jianmu
1
0
Fork 0
Code Issues Pull Requests 1 Actions Packages Projects Releases Wiki Activity

add some logs

This commit is contained in:
Shengliang Guan 2022-01-03 23:20:29 -08:00
parent 1826b3035f
commit c94f30e383
8 changed files with 64 additions and 35 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

2
source/dnode/mnode/impl/src/mndDnode.c
View File

@ -354,7 +354,7 @@ static int32_t mndProcessStatusMsg(SMnodeMsg *pMsg) {
} }
if (pStatus->dnodeId == 0) { if (pStatus->dnodeId == 0) {
mDebug("dnode:%d %s, first access, set clusterId %" PRId64, pDnode->id, pDnode->ep, pMnode->clusterId); mDebug("dnode:%d, %s first access, set clusterId %" PRId64, pDnode->id, pDnode->ep, pMnode->clusterId);
} else { } else {
if (pStatus->clusterId != pMnode->clusterId) { if (pStatus->clusterId != pMnode->clusterId) {
if (pDnode != NULL) { if (pDnode != NULL) {

2
source/dnode/mnode/impl/src/mndShow.c
View File

@ -152,7 +152,7 @@ static int32_t mndProcessShowMsg(SMnodeMsg *pMnodeMsg) {
} }
int32_t code = (*metaFp)(pMnodeMsg, pShow, &pRsp->tableMeta); int32_t code = (*metaFp)(pMnodeMsg, pShow, &pRsp->tableMeta);
mDebug("show:0x%" PRIx64 ", get meta finished, numOfRows:%d cols:%d type:%s result:%s", pShow->id, pShow->numOfRows, mDebug("show:0x%" PRIx64 ", get meta finished, numOfRows:%d cols:%d type:%s, result:%s", pShow->id, pShow->numOfRows,
pShow->numOfColumns, mndShowStr(type), tstrerror(code)); pShow->numOfColumns, mndShowStr(type), tstrerror(code));
if (code == TSDB_CODE_SUCCESS) { if (code == TSDB_CODE_SUCCESS) {

16
source/dnode/mnode/impl/src/mndSync.c
View File

@ -52,11 +52,12 @@ static int32_t mndRestoreWal(SMnode *pMnode) {
SWalReadHandle *pHandle = walOpenReadHandle(pWal); SWalReadHandle *pHandle = walOpenReadHandle(pWal);
if (pHandle == NULL) return -1; if (pHandle == NULL) return -1;
int64_t start = walGetFirstVer(pWal); int64_t first = walGetFirstVer(pWal);
int64_t end = walGetLastVer(pWal); int64_t last = walGetLastVer(pWal);
start = MAX(lastSdbVer + 1, start); mDebug("restore sdb wal start, sdb ver:%" PRId64 ", wal first:%" PRId64 " last:%" PRId64, lastSdbVer, first, last);
for (int64_t ver = start; ver >= 0 && ver <= end; ++ver) { first = MAX(lastSdbVer + 1, first);
for (int64_t ver = first; ver >= 0 && ver <= last; ++ver) {
if (walReadWithHandle(pHandle, ver) < 0) { if (walReadWithHandle(pHandle, ver) < 0) {
mError("failed to read by wal handle since %s, ver:%" PRId64, terrstr(), ver); mError("failed to read by wal handle since %s, ver:%" PRId64, terrstr(), ver);
goto WAL_RESTORE_OVER; goto WAL_RESTORE_OVER;
@ -76,15 +77,18 @@ static int32_t mndRestoreWal(SMnode *pMnode) {
} }
sdbUpdateVer(pSdb, 1); sdbUpdateVer(pSdb, 1);
mDebug("wal:%" PRId64 ", is restored", ver);
} }
int64_t sdbVer = sdbUpdateVer(pSdb, 0); int64_t sdbVer = sdbUpdateVer(pSdb, 0);
mDebug("restore sdb wal finished, sdb ver:%" PRId64, sdbVer);
if (walBeginSnapshot(pWal, sdbVer) < 0) { if (walBeginSnapshot(pWal, sdbVer) < 0) {
goto WAL_RESTORE_OVER; goto WAL_RESTORE_OVER;
} }
if (sdbVer != lastSdbVer) { if (sdbVer != lastSdbVer) {
mInfo("sdb restore wal from %" PRId64 " to %" PRId64, lastSdbVer, sdbVer); mInfo("sdb restored from %" PRId64 " to %" PRId64 ", write file", lastSdbVer, sdbVer);
if (sdbWriteFile(pSdb) != 0) { if (sdbWriteFile(pSdb) != 0) {
goto WAL_RESTORE_OVER; goto WAL_RESTORE_OVER;
} }
@ -147,7 +151,7 @@ int32_t mndSyncPropose(SMnode *pMnode, SSdbRaw *pRaw) {
return -1; return -1;
} }
mTrace("raw:%p has been write to wal, ver:%" PRId64, pRaw, ver); mTrace("raw:%p, write to wal, ver:%" PRId64, pRaw, ver);
walCommit(pWal, ver); walCommit(pWal, ver);
walFsync(pWal, true); walFsync(pWal, true);

14
source/dnode/mnode/impl/src/mndTrans.c
View File

@ -169,7 +169,7 @@ TRANS_ENCODE_OVER:
return NULL; return NULL;
} }
mTrace("trans:%d, encode to raw:%p, len:%d", pTrans->id, pRaw, dataPos); mTrace("trans:%d, encode to raw:%p, row:%p len:%d", pTrans->id, pRaw, pTrans, dataPos);
return pRaw; return pRaw;
} }
@ -226,6 +226,7 @@ static SSdbRow *mndTransActionDecode(SSdbRaw *pRaw) {
SDB_GET_INT32(pRaw, dataPos, &dataLen, TRANS_DECODE_OVER) SDB_GET_INT32(pRaw, dataPos, &dataLen, TRANS_DECODE_OVER)
pData = malloc(dataLen); pData = malloc(dataLen);
if (pData == NULL) goto TRANS_DECODE_OVER; if (pData == NULL) goto TRANS_DECODE_OVER;
mTrace("raw:%p, is created", pData);
SDB_GET_BINARY(pRaw, dataPos, pData, dataLen, TRANS_DECODE_OVER); SDB_GET_BINARY(pRaw, dataPos, pData, dataLen, TRANS_DECODE_OVER);
if (taosArrayPush(pTrans->redoLogs, &pData) == NULL) goto TRANS_DECODE_OVER; if (taosArrayPush(pTrans->redoLogs, &pData) == NULL) goto TRANS_DECODE_OVER;
pData = NULL; pData = NULL;
@ -235,6 +236,7 @@ static SSdbRow *mndTransActionDecode(SSdbRaw *pRaw) {
SDB_GET_INT32(pRaw, dataPos, &dataLen, TRANS_DECODE_OVER) SDB_GET_INT32(pRaw, dataPos, &dataLen, TRANS_DECODE_OVER)
pData = malloc(dataLen); pData = malloc(dataLen);
if (pData == NULL) goto TRANS_DECODE_OVER; if (pData == NULL) goto TRANS_DECODE_OVER;
mTrace("raw:%p, is created", pData);
SDB_GET_BINARY(pRaw, dataPos, pData, dataLen, TRANS_DECODE_OVER); SDB_GET_BINARY(pRaw, dataPos, pData, dataLen, TRANS_DECODE_OVER);
if (taosArrayPush(pTrans->undoLogs, &pData) == NULL) goto TRANS_DECODE_OVER; if (taosArrayPush(pTrans->undoLogs, &pData) == NULL) goto TRANS_DECODE_OVER;
pData = NULL; pData = NULL;
@ -243,6 +245,8 @@ static SSdbRow *mndTransActionDecode(SSdbRaw *pRaw) {
for (int32_t i = 0; i < commitLogNum; ++i) { for (int32_t i = 0; i < commitLogNum; ++i) {
SDB_GET_INT32(pRaw, dataPos, &dataLen, TRANS_DECODE_OVER) SDB_GET_INT32(pRaw, dataPos, &dataLen, TRANS_DECODE_OVER)
pData = malloc(dataLen); pData = malloc(dataLen);
if (pData == NULL) goto TRANS_DECODE_OVER;
mTrace("raw:%p, is created", pData);
SDB_GET_BINARY(pRaw, dataPos, pData, dataLen, TRANS_DECODE_OVER); SDB_GET_BINARY(pRaw, dataPos, pData, dataLen, TRANS_DECODE_OVER);
if (taosArrayPush(pTrans->commitLogs, &pData) == NULL) goto TRANS_DECODE_OVER; if (taosArrayPush(pTrans->commitLogs, &pData) == NULL) goto TRANS_DECODE_OVER;
pData = NULL; pData = NULL;
@ -284,13 +288,13 @@ TRANS_DECODE_OVER:
return NULL; return NULL;
} }
mTrace("trans:%d, decode from raw:%p, data:%p", pTrans->id, pRaw, pTrans); mTrace("trans:%d, decode from raw:%p, row:%p", pTrans->id, pRaw, pTrans);
return pRow; return pRow;
} }
static int32_t mndTransActionInsert(SSdb *pSdb, STrans *pTrans) { static int32_t mndTransActionInsert(SSdb *pSdb, STrans *pTrans) {
pTrans->stage = TRN_STAGE_PREPARE; pTrans->stage = TRN_STAGE_PREPARE;
mTrace("trans:%d, perform insert action, data:%p", pTrans->id, pTrans); mTrace("trans:%d, perform insert action, row:%p", pTrans->id, pTrans);
return 0; return 0;
} }
@ -303,13 +307,13 @@ static void mndTransDropData(STrans *pTrans) {
} }
static int32_t mndTransActionDelete(SSdb *pSdb, STrans *pTrans) { static int32_t mndTransActionDelete(SSdb *pSdb, STrans *pTrans) {
mTrace("trans:%d, perform delete action, data:%p", pTrans->id, pTrans); mTrace("trans:%d, perform delete action, row:%p", pTrans->id, pTrans);
mndTransDropData(pTrans); mndTransDropData(pTrans);
return 0; return 0;
} }
static int32_t mndTransActionUpdate(SSdb *pSdb, STrans *pOldTrans, STrans *pNewTrans) { static int32_t mndTransActionUpdate(SSdb *pSdb, STrans *pOldTrans, STrans *pNewTrans) {
mTrace("trans:%d, perform update action, data:%p", pOldTrans->id, pOldTrans); mTrace("trans:%d, perform update action, old_row:%p new_row:%p", pOldTrans->id, pOldTrans, pNewTrans);
pOldTrans->stage = pNewTrans->stage; pOldTrans->stage = pNewTrans->stage;
return 0; return 0;
} }

28
source/dnode/mnode/impl/src/mnode.c
View File

@ -185,7 +185,7 @@ static void mndCleanupSteps(SMnode *pMnode, int32_t pos) {
for (int32_t s = pos; s >= 0; s--) { for (int32_t s = pos; s >= 0; s--) {
SMnodeStep *pStep = taosArrayGet(pMnode->pSteps, s); SMnodeStep *pStep = taosArrayGet(pMnode->pSteps, s);
mDebug("step:%s will cleanup", pStep->name); mDebug("%s will cleanup", pStep->name);
if (pStep->cleanupFp != NULL) { if (pStep->cleanupFp != NULL) {
(*pStep->cleanupFp)(pMnode); (*pStep->cleanupFp)(pMnode);
} }
@ -204,12 +204,12 @@ static int32_t mndExecSteps(SMnode *pMnode) {
if ((*pStep->initFp)(pMnode) != 0) { if ((*pStep->initFp)(pMnode) != 0) {
int32_t code = terrno; int32_t code = terrno;
mError("step:%s exec failed since %s, start to cleanup", pStep->name, terrstr()); mError("%s exec failed since %s, start to cleanup", pStep->name, terrstr());
mndCleanupSteps(pMnode, pos); mndCleanupSteps(pMnode, pos);
terrno = code; terrno = code;
return -1; return -1;
} else { } else {
mDebug("step:%s is initialized", pStep->name); mDebug("%s is initialized", pStep->name);
} }
} }
@ -357,7 +357,7 @@ SMnodeMsg *mndInitMsg(SMnode *pMnode, SRpcMsg *pRpcMsg) {
SMnodeMsg *pMsg = taosAllocateQitem(sizeof(SMnodeMsg)); SMnodeMsg *pMsg = taosAllocateQitem(sizeof(SMnodeMsg));
if (pMsg == NULL) { if (pMsg == NULL) {
terrno = TSDB_CODE_OUT_OF_MEMORY; terrno = TSDB_CODE_OUT_OF_MEMORY;
mError("RPC:%p, app:%p failed to create msg since %s", pRpcMsg->handle, pRpcMsg->ahandle, terrstr()); mError("failed to create msg since %s, app:%p RPC:%p", terrstr(), pRpcMsg->ahandle, pRpcMsg->handle);
return NULL; return NULL;
} }
@ -365,7 +365,7 @@ SMnodeMsg *mndInitMsg(SMnode *pMnode, SRpcMsg *pRpcMsg) {
if ((pRpcMsg->msgType & 1U) && rpcGetConnInfo(pRpcMsg->handle, &connInfo) != 0) { if ((pRpcMsg->msgType & 1U) && rpcGetConnInfo(pRpcMsg->handle, &connInfo) != 0) {
taosFreeQitem(pMsg); taosFreeQitem(pMsg);
terrno = TSDB_CODE_MND_NO_USER_FROM_CONN; terrno = TSDB_CODE_MND_NO_USER_FROM_CONN;
mError("RPC:%p, app:%p failed to create msg since %s", pRpcMsg->handle, pRpcMsg->ahandle, terrstr()); mError("failed to create msg since %s, app:%p RPC:%p", terrstr(), pRpcMsg->ahandle, pRpcMsg->handle);
return NULL; return NULL;
} }
memcpy(pMsg->user, connInfo.user, TSDB_USER_LEN); memcpy(pMsg->user, connInfo.user, TSDB_USER_LEN);
@ -374,12 +374,12 @@ SMnodeMsg *mndInitMsg(SMnode *pMnode, SRpcMsg *pRpcMsg) {
pMsg->rpcMsg = *pRpcMsg; pMsg->rpcMsg = *pRpcMsg;
pMsg->createdTime = taosGetTimestampSec(); pMsg->createdTime = taosGetTimestampSec();
mTrace("msg:%p, app:%p is created, RPC:%p", pMsg, pRpcMsg->ahandle, pRpcMsg->handle); mTrace("msg:%p, is created, app:%p RPC:%p user:%s", pMsg, pRpcMsg->ahandle, pRpcMsg->handle, pMsg->user);
return pMsg; return pMsg;
} }
void mndCleanupMsg(SMnodeMsg *pMsg) { void mndCleanupMsg(SMnodeMsg *pMsg) {
mTrace("msg:%p, app:%p is destroyed, RPC:%p", pMsg, pMsg->rpcMsg.ahandle, pMsg->rpcMsg.handle); mTrace("msg:%p, is destroyed, app:%p RPC:%p", pMsg, pMsg->rpcMsg.ahandle, pMsg->rpcMsg.handle);
rpcFreeCont(pMsg->rpcMsg.pCont); rpcFreeCont(pMsg->rpcMsg.pCont);
pMsg->rpcMsg.pCont = NULL; pMsg->rpcMsg.pCont = NULL;
taosFreeQitem(pMsg); taosFreeQitem(pMsg);
@ -397,37 +397,37 @@ void mndProcessMsg(SMnodeMsg *pMsg) {
void *ahandle = pMsg->rpcMsg.ahandle; void *ahandle = pMsg->rpcMsg.ahandle;
bool isReq = (msgType & 1U); bool isReq = (msgType & 1U);
mTrace("msg:%p, app:%p type:%s will be processed", pMsg, ahandle, TMSG_INFO(msgType)); mTrace("msg:%p, type:%s will be processed, app:%p", pMsg, TMSG_INFO(msgType), ahandle);
if (isReq && !mndIsMaster(pMnode)) { if (isReq && !mndIsMaster(pMnode)) {
code = TSDB_CODE_APP_NOT_READY; code = TSDB_CODE_APP_NOT_READY;
mDebug("msg:%p, app:%p failed to process since %s", pMsg, ahandle, terrstr()); mDebug("msg:%p, failed to process since %s, app:%p", pMsg, terrstr(), ahandle);
goto PROCESS_RPC_END; goto PROCESS_RPC_END;
} }
if (isReq && pMsg->rpcMsg.pCont == NULL) { if (isReq && pMsg->rpcMsg.pCont == NULL) {
code = TSDB_CODE_MND_INVALID_MSG_LEN; code = TSDB_CODE_MND_INVALID_MSG_LEN;
mError("msg:%p, app:%p failed to process since %s", pMsg, ahandle, terrstr()); mError("msg:%p, failed to process since %s, app:%p", pMsg, terrstr(), ahandle);
goto PROCESS_RPC_END; goto PROCESS_RPC_END;
} }
MndMsgFp fp = pMnode->msgFp[TMSG_INDEX(msgType)]; MndMsgFp fp = pMnode->msgFp[TMSG_INDEX(msgType)];
if (fp == NULL) { if (fp == NULL) {
code = TSDB_CODE_MSG_NOT_PROCESSED; code = TSDB_CODE_MSG_NOT_PROCESSED;
mError("msg:%p, app:%p failed to process since no handle", pMsg, ahandle); mError("msg:%p, failed to process since no msg handle, app:%p", pMsg, ahandle);
goto PROCESS_RPC_END; goto PROCESS_RPC_END;
} }
code = (*fp)(pMsg); code = (*fp)(pMsg);
if (code == TSDB_CODE_MND_ACTION_IN_PROGRESS) { if (code == TSDB_CODE_MND_ACTION_IN_PROGRESS) {
mTrace("msg:%p, app:%p in progressing", pMsg, ahandle); mTrace("msg:%p, in progress, app:%p", pMsg, ahandle);
return; return;
} else if (code != 0) { } else if (code != 0) {
code = terrno; code = terrno;
mError("msg:%p, app:%p failed to process since %s", pMsg, ahandle, terrstr()); mError("msg:%p, failed to process since %s, app:%p", pMsg, terrstr(), ahandle);
goto PROCESS_RPC_END; goto PROCESS_RPC_END;
} else { } else {
mTrace("msg:%p, app:%p is processed", pMsg, ahandle); mTrace("msg:%p, is processed, app:%p", pMsg, ahandle);
} }
PROCESS_RPC_END: PROCESS_RPC_END:

4
source/dnode/mnode/sdb/src/sdb.c
View File

@ -65,7 +65,7 @@ void sdbCleanup(SSdb *pSdb) {
mDebug("start to cleanup sdb"); mDebug("start to cleanup sdb");
if (pSdb->curVer != pSdb->lastCommitVer) { if (pSdb->curVer != pSdb->lastCommitVer) {
mDebug("write sdb file for curVer:% " PRId64 " and lastCommitVer:%" PRId64, pSdb->curVer, pSdb->lastCommitVer); mDebug("write sdb file for current ver:%" PRId64 " != last commit ver:%" PRId64, pSdb->curVer, pSdb->lastCommitVer);
sdbWriteFile(pSdb); sdbWriteFile(pSdb);
} }
@ -138,7 +138,7 @@ int32_t sdbSetTable(SSdb *pSdb, SSdbTable table) {
pSdb->maxId[sdbType] = 0; pSdb->maxId[sdbType] = 0;
pSdb->hashObjs[sdbType] = hash; pSdb->hashObjs[sdbType] = hash;
taosInitRWLatch(&pSdb->locks[sdbType]); taosInitRWLatch(&pSdb->locks[sdbType]);
mDebug("sdb table:%d is initialized", sdbType); mDebug("sdb table:%s is initialized", sdbTableName(sdbType));
return 0; return 0;
} }

1
source/dnode/mnode/sdb/src/sdbFile.c
View File

@ -146,6 +146,7 @@ int32_t sdbReadFile(SSdb *pSdb) {
char file[PATH_MAX] = {0}; char file[PATH_MAX] = {0};
snprintf(file, sizeof(file), "%s%ssdb.data", pSdb->currDir, TD_DIRSEP); snprintf(file, sizeof(file), "%s%ssdb.data", pSdb->currDir, TD_DIRSEP);
mDebug("start to read file:%s", file);
FileFd fd = taosOpenFileRead(file); FileFd fd = taosOpenFileRead(file);
if (fd <= 0) { if (fd <= 0) {

32
source/dnode/mnode/sdb/src/sdbHash.c
View File

@ -57,18 +57,35 @@ const char *sdbTableName(ESdbType type) {
} }
} }
static const char *sdbStatusStr(ESdbStatus status) {
switch (status) {
case SDB_STATUS_CREATING:
return "creating";
case SDB_STATUS_UPDATING:
return "updating";
case SDB_STATUS_DROPPING:
return "dropping";
case SDB_STATUS_READY:
return "ready";
case SDB_STATUS_DROPPED:
return "dropped";
default:
return "undefine";
}
}
void sdbPrintOper(SSdb *pSdb, SSdbRow *pRow, const char *oper) { void sdbPrintOper(SSdb *pSdb, SSdbRow *pRow, const char *oper) {
EKeyType keyType = pSdb->keyTypes[pRow->type]; EKeyType keyType = pSdb->keyTypes[pRow->type];
if (keyType == SDB_KEY_BINARY) { if (keyType == SDB_KEY_BINARY) {
mTrace("%s:%s, refCount:%d oper:%s row:%p", sdbTableName(pRow->type), (char *)pRow->pObj, pRow->refCount, oper, mTrace("%s:%s, refCount:%d oper:%s row:%p status:%s", sdbTableName(pRow->type), (char *)pRow->pObj, pRow->refCount,
pRow->pObj); oper, pRow->pObj, sdbStatusStr(pRow->status));
} else if (keyType == SDB_KEY_INT32) { } else if (keyType == SDB_KEY_INT32) {
mTrace("%s:%d, refCount:%d oper:%s row:%p", sdbTableName(pRow->type), *(int32_t *)pRow->pObj, pRow->refCount, oper, mTrace("%s:%d, refCount:%d oper:%s row:%p status:%s", sdbTableName(pRow->type), *(int32_t *)pRow->pObj,
pRow->pObj); pRow->refCount, oper, pRow->pObj, sdbStatusStr(pRow->status));
} else if (keyType == SDB_KEY_INT64) { } else if (keyType == SDB_KEY_INT64) {
mTrace("%s:%" PRId64 ", refCount:%d oper:%s row:%p", sdbTableName(pRow->type), *(int64_t *)pRow->pObj, mTrace("%s:%" PRId64 ", refCount:%d oper:%s row:%p status:%s", sdbTableName(pRow->type), *(int64_t *)pRow->pObj,
pRow->refCount, oper, pRow->pObj); pRow->refCount, oper, pRow->pObj, sdbStatusStr(pRow->status));
} else { } else {
} }
} }
@ -165,6 +182,7 @@ static int32_t sdbUpdateRow(SSdb *pSdb, SHashObj *hash, SSdbRaw *pRaw, SSdbRow *
SSdbRow *pOldRow = *ppOldRow; SSdbRow *pOldRow = *ppOldRow;
pOldRow->status = pRaw->status; pOldRow->status = pRaw->status;
sdbPrintOper(pSdb, pOldRow, "updateRow");
taosRUnLockLatch(pLock); taosRUnLockLatch(pLock);
int32_t code = 0; int32_t code = 0;
@ -193,6 +211,8 @@ static int32_t sdbDeleteRow(SSdb *pSdb, SHashObj *hash, SSdbRaw *pRaw, SSdbRow *
SSdbRow *pOldRow = *ppOldRow; SSdbRow *pOldRow = *ppOldRow;
pOldRow->status = pRaw->status; pOldRow->status = pRaw->status;
sdbPrintOper(pSdb, pOldRow, "deleteRow");
taosHashRemove(hash, pOldRow->pObj, keySize); taosHashRemove(hash, pOldRow->pObj, keySize);
taosWUnLockLatch(pLock); taosWUnLockLatch(pLock);