diff --git a/source/dnode/mgmt/exe/dmMain.c b/source/dnode/mgmt/exe/dmMain.c index 81df34ef4a..5dc896d048 100644 --- a/source/dnode/mgmt/exe/dmMain.c +++ b/source/dnode/mgmt/exe/dmMain.c @@ -191,9 +191,9 @@ static int32_t dmRunDnode() { dmSetSignalHandle(); } - dInfo("start the service"); + dInfo("start to run dnode"); int32_t code = dmRun(pDnode); - dInfo("start shutting down the service"); + dInfo("shutting down the service"); global.pDnode = NULL; dmClose(pDnode); diff --git a/source/dnode/mgmt/mgmt_dnode/src/dmInt.c b/source/dnode/mgmt/mgmt_dnode/src/dmInt.c index 1a4a85f76a..5f8e015f14 100644 --- a/source/dnode/mgmt/mgmt_dnode/src/dmInt.c +++ b/source/dnode/mgmt/mgmt_dnode/src/dmInt.c @@ -33,7 +33,6 @@ static void dmStopMgmt(SDnodeMgmt *pMgmt) { } static int32_t dmOpenMgmt(SMgmtInputOpt *pInput, SMgmtOutputOpt *pOutput) { - dInfo("dnode-mgmt start to init"); SDnodeMgmt *pMgmt = taosMemoryCalloc(1, sizeof(SDnodeMgmt)); if (pMgmt == NULL) { terrno = TSDB_CODE_OUT_OF_MEMORY; @@ -58,15 +57,12 @@ static int32_t dmOpenMgmt(SMgmtInputOpt *pInput, SMgmtOutputOpt *pOutput) { } pOutput->pMgmt = pMgmt; - dInfo("dnode-mgmt is initialized"); return 0; } static void dmCloseMgmt(SDnodeMgmt *pMgmt) { - dInfo("dnode-mgmt start to clean up"); dmStopWorker(pMgmt); taosMemoryFree(pMgmt); - dInfo("dnode-mgmt is cleaned up"); } static int32_t dmRequireMgmt(const SMgmtInputOpt *pInput, bool *required) { diff --git a/source/dnode/mgmt/node_mgmt/src/dmMgmt.c b/source/dnode/mgmt/node_mgmt/src/dmMgmt.c index b047e53260..c1e497a9de 100644 --- a/source/dnode/mgmt/node_mgmt/src/dmMgmt.c +++ b/source/dnode/mgmt/node_mgmt/src/dmMgmt.c @@ -212,7 +212,7 @@ SDnode *dmCreate(const SDnodeOpt *pOption) { } dmReportStartup(pDnode, "dnode-transport", "initialized"); - dInfo("dnode is created, data:%p", pDnode); + dInfo("dnode is created, ptr:%p", pDnode); code = 0; _OVER: @@ -231,7 +231,7 @@ void dmClose(SDnode *pDnode) { dmCleanupClient(pDnode); dmCleanupServer(pDnode); dmClearVars(pDnode); - dInfo("dnode is closed, data:%p", pDnode); + dInfo("dnode is closed, ptr:%p", pDnode); } void dmSetStatus(SDnode *pDnode, EDndRunStatus status) { @@ -254,7 +254,7 @@ SMgmtWrapper *dmAcquireWrapper(SDnode *pDnode, EDndNodeType ntype) { taosRLockLatch(&pWrapper->latch); if (pWrapper->deployed) { int32_t refCount = atomic_add_fetch_32(&pWrapper->refCount, 1); - dTrace("node:%s, is acquired, refCount:%d", pWrapper->name, refCount); + dTrace("node:%s, is acquired, ref:%d", pWrapper->name, refCount); } else { terrno = TSDB_CODE_NODE_NOT_DEPLOYED; pRetWrapper = NULL; @@ -270,7 +270,7 @@ int32_t dmMarkWrapper(SMgmtWrapper *pWrapper) { taosRLockLatch(&pWrapper->latch); if (pWrapper->deployed || (InParentProc(pWrapper->proc.ptype) && pWrapper->required)) { int32_t refCount = atomic_add_fetch_32(&pWrapper->refCount, 1); - dTrace("node:%s, is marked, refCount:%d", pWrapper->name, refCount); + dTrace("node:%s, is marked, ref:%d", pWrapper->name, refCount); } else { terrno = TSDB_CODE_NODE_NOT_DEPLOYED; code = -1; @@ -286,14 +286,14 @@ void dmReleaseWrapper(SMgmtWrapper *pWrapper) { taosRLockLatch(&pWrapper->latch); int32_t refCount = atomic_sub_fetch_32(&pWrapper->refCount, 1); taosRUnLockLatch(&pWrapper->latch); - dTrace("node:%s, is released, refCount:%d", pWrapper->name, refCount); + dTrace("node:%s, is released, ref:%d", pWrapper->name, refCount); } void dmReportStartup(SDnode *pDnode, const char *pName, const char *pDesc) { SStartupInfo *pStartup = &pDnode->startup; tstrncpy(pStartup->name, pName, TSDB_STEP_NAME_LEN); tstrncpy(pStartup->desc, pDesc, TSDB_STEP_DESC_LEN); - dInfo("step:%s, %s", pStartup->name, pStartup->desc); + dDebug("step:%s, %s", pStartup->name, pStartup->desc); } void dmReportStartupByWrapper(SMgmtWrapper *pWrapper, const char *pName, const char *pDesc) { diff --git a/source/dnode/mgmt/node_mgmt/src/dmNodes.c b/source/dnode/mgmt/node_mgmt/src/dmNodes.c index 4fdd862652..97a32f87b4 100644 --- a/source/dnode/mgmt/node_mgmt/src/dmNodes.c +++ b/source/dnode/mgmt/node_mgmt/src/dmNodes.c @@ -99,15 +99,17 @@ int32_t dmOpenNode(SMgmtWrapper *pWrapper) { } if (OnlyInSingleProc(pWrapper->proc.ptype)) { + dInfo("node:%s, start to open", pWrapper->name); if ((*pWrapper->func.openFp)(&input, &output) != 0) { dError("node:%s, failed to open since %s", pWrapper->name, terrstr()); return -1; } - dDebug("node:%s, has been opened", pWrapper->name); + dInfo("node:%s, has been opened", pWrapper->name); pWrapper->deployed = true; } if (InChildProc(pWrapper->proc.ptype)) { + dDebug("node:%s, start to open", pWrapper->name); if ((*pWrapper->func.openFp)(&input, &output) != 0) { dError("node:%s, failed to open since %s", pWrapper->name, terrstr()); return -1; @@ -123,6 +125,7 @@ int32_t dmOpenNode(SMgmtWrapper *pWrapper) { } if (InParentProc(pWrapper->proc.ptype)) { + dDebug("node:%s, start to open", pWrapper->name); if (dmInitParentProc(pWrapper) != 0) { return -1; } @@ -145,9 +148,13 @@ int32_t dmOpenNode(SMgmtWrapper *pWrapper) { int32_t dmStartNode(SMgmtWrapper *pWrapper) { if (OnlyInParentProc(pWrapper->proc.ptype)) return 0; - if (pWrapper->func.startFp != NULL && (*pWrapper->func.startFp)(pWrapper->pMgmt) != 0) { - dError("node:%s, failed to start since %s", pWrapper->name, terrstr()); - return -1; + if (pWrapper->func.startFp != NULL) { + dDebug("node:%s, start to start", pWrapper->name); + if ((*pWrapper->func.startFp)(pWrapper->pMgmt) != 0) { + dError("node:%s, failed to start since %s", pWrapper->name, terrstr()); + return -1; + } + dDebug("node:%s, has been started", pWrapper->name); } dmReportStartup(pWrapper->pDnode, pWrapper->name, "started"); @@ -156,6 +163,7 @@ int32_t dmStartNode(SMgmtWrapper *pWrapper) { void dmStopNode(SMgmtWrapper *pWrapper) { if (pWrapper->func.stopFp != NULL && pWrapper->pMgmt != NULL) { + dDebug("node:%s, start to stop", pWrapper->name); (*pWrapper->func.stopFp)(pWrapper->pMgmt); dDebug("node:%s, has been stopped", pWrapper->name); } diff --git a/source/dnode/mgmt/node_mgmt/src/dmProc.c b/source/dnode/mgmt/node_mgmt/src/dmProc.c index 5ce7bb5b14..493a35b81b 100644 --- a/source/dnode/mgmt/node_mgmt/src/dmProc.c +++ b/source/dnode/mgmt/node_mgmt/src/dmProc.c @@ -185,8 +185,8 @@ static int32_t dmPushToProcQueue(SProc *proc, SProcQueue *queue, const char *pHe taosThreadMutexUnlock(&queue->mutex); tsem_post(&queue->sem); - dTrace("node:%s, push proc msg at pos:%d ftype:%d remain:%d handle:%p ref:%" PRId64 ", head:%d %p body:%d %p", - queue->name, pos, ftype, queue->items, (void *)handle, handleRef, headLen, pHead, bodyLen, pBody); + dTrace("node:%s, push msg:%p:%d cont:%p%d handle:%p, ftype:%d pos:%d remain:%d", queue->name, pHead, headLen, pBody, + bodyLen, (void *)handle, ftype, pos, queue->items); return 0; } @@ -315,31 +315,31 @@ static void *dmConsumChildQueue(void *param) { EProcFuncType ftype = PROC_FUNC_REQ; SNodeMsg *pReq = NULL; - dDebug("node:%s, start to consume from child queue", proc->name); + dDebug("node:%s, start to consume from cqueue", proc->name); do { numOfMsgs = dmPopFromProcQueue(queue, &pHead, &headLen, &pBody, &bodyLen, &ftype); if (numOfMsgs == 0) { - dDebug("node:%s, get no msg from child queue and exit thread", proc->name); + dDebug("node:%s, get no msg from cueue and exit thread", proc->name); break; } if (numOfMsgs < 0) { - dError("node:%s, get no msg from child queue since %s", proc->name, terrstr()); + dError("node:%s, get no msg from cqueue since %s", proc->name, terrstr()); taosMsleep(1); continue; } if (ftype != PROC_FUNC_REQ) { - dFatal("node:%s, msg:%p from child queue, invalid ftype:%d", proc->name, pHead, ftype); + dFatal("node:%s, msg:%p from cqueue, invalid ftype:%d", proc->name, pHead, ftype); taosFreeQitem(pHead); rpcFreeCont(pBody); } else { - dTrace("node:%s, msg:%p from child queue", proc->name, pHead); + dTrace("node:%s, msg:%p from cueue", proc->name, pHead); pReq = pHead; pReq->rpcMsg.pCont = pBody; code = dmProcessNodeMsg(pWrapper, pReq); if (code != 0) { - dError("node:%s, failed to process msg:%p since %s, put into parent queue", proc->name, pReq, terrstr()); + dError("node:%s, failed to process msg:%p since %s, put into pqueue", proc->name, pReq, terrstr()); SRpcMsg rspMsg = { .handle = pReq->rpcMsg.handle, .ahandle = pReq->rpcMsg.ahandle, @@ -371,16 +371,16 @@ static void *dmConsumParentQueue(void *param) { EProcFuncType ftype = PROC_FUNC_REQ; SRpcMsg *pRsp = NULL; - dDebug("node:%s, start to consume from parent queue", proc->name); + dDebug("node:%s, start to consume from pqueue", proc->name); do { numOfMsgs = dmPopFromProcQueue(queue, &pHead, &headLen, &pBody, &bodyLen, &ftype); if (numOfMsgs == 0) { - dDebug("node:%s, get no msg from parent queue and exit thread", proc->name); + dDebug("node:%s, get no msg from pqueue and exit thread", proc->name); break; } if (numOfMsgs < 0) { - dError("node:%s, get no msg from parent queue since %s", proc->name, terrstr()); + dError("node:%s, get no msg from pqueue since %s", proc->name, terrstr()); taosMsleep(1); continue; } @@ -388,22 +388,22 @@ static void *dmConsumParentQueue(void *param) { if (ftype == PROC_FUNC_RSP) { pRsp = pHead; pRsp->pCont = pBody; - dTrace("node:%s, rsp msg:%p from parent queue, code:0x%04x handle:%p", proc->name, pRsp, code, pRsp->handle); + dTrace("node:%s, rsp msg:%p from pqueue, code:0x%04x handle:%p", proc->name, pRsp, code, pRsp->handle); dmRemoveProcRpcHandle(proc, pRsp->handle); rpcSendResponse(pRsp); } else if (ftype == PROC_FUNC_REGIST) { pRsp = pHead; - dTrace("node:%s, regist msg:%p from parent queue, code:0x%04x handle:%p", proc->name, pRsp, code, pRsp->handle); + dTrace("node:%s, regist msg:%p from pqueue, code:0x%04x handle:%p", proc->name, pRsp, code, pRsp->handle); rpcRegisterBrokenLinkArg(pRsp); rpcFreeCont(pBody); } else if (ftype == PROC_FUNC_RELEASE) { pRsp = pHead; - dTrace("node:%s, release msg:%p from parent queue, code:0x%04x handle:%p", proc->name, pRsp, code, pRsp->handle); + dTrace("node:%s, release msg:%p from pqueue, code:0x%04x handle:%p", proc->name, pRsp, code, pRsp->handle); dmRemoveProcRpcHandle(proc, pRsp->handle); rpcReleaseHandle(pRsp->handle, (int8_t)pRsp->code); rpcFreeCont(pBody); } else { - dFatal("node:%s, msg:%p get from parent queue, invalid ftype:%d", proc->name, pHead, ftype); + dFatal("node:%s, msg:%p get from pqueue, invalid ftype:%d", proc->name, pHead, ftype); rpcFreeCont(pBody); } @@ -502,7 +502,7 @@ void dmPutToProcPQueue(SProc *proc, const void *pHead, int16_t headLen, const vo EProcFuncType ftype) { int32_t retry = 0; while (dmPushToProcQueue(proc, proc->pqueue, pHead, headLen, pBody, bodyLen, 0, 0, ftype) != 0) { - dWarn("node:%s, failed to put msg:%p to parent queue since %s, retry:%d", proc->name, pHead, terrstr(), retry); + dWarn("node:%s, failed to put msg:%p to pqueue since %s, retry:%d", proc->name, pHead, terrstr(), retry); retry++; taosMsleep(retry); } diff --git a/source/dnode/mgmt/node_mgmt/src/dmTransport.c b/source/dnode/mgmt/node_mgmt/src/dmTransport.c index 6d5bedfff5..f9cebeb7f5 100644 --- a/source/dnode/mgmt/node_mgmt/src/dmTransport.c +++ b/source/dnode/mgmt/node_mgmt/src/dmTransport.c @@ -121,13 +121,13 @@ static void dmProcessRpcMsg(SDnode *pDnode, SRpcMsg *pRpc, SEpSet *pEpSet) { } } + dTrace("msg:%s is received, handle:%p app:%p", TMSG_INFO(msgType), pRpc->handle, pRpc->ahandle); if (dmMarkWrapper(pWrapper) != 0) { goto _OVER; } else { needRelease = true; } - dTrace("msg:%s is received, handle:%p app:%p", TMSG_INFO(msgType), pRpc->handle, pRpc->ahandle); pMsg = taosAllocateQitem(sizeof(SNodeMsg), RPC_QITEM); if (pMsg == NULL) { goto _OVER; @@ -138,7 +138,7 @@ static void dmProcessRpcMsg(SDnode *pDnode, SRpcMsg *pRpc, SEpSet *pEpSet) { } if (InParentProc(pWrapper->proc.ptype)) { - dTrace("msg:%p, put into child queue, handle:%p", pMsg, pRpc->handle); + dTrace("msg:%p, put into cqueue, handle:%p ref:%" PRId64, pMsg, pRpc->handle, pRpc->refId); code = dmPutToProcCQueue(&pWrapper->proc, pMsg, sizeof(SNodeMsg), pRpc->pCont, pRpc->contLen, (isReq && (pRpc->code == 0)) ? pRpc->handle : NULL, pRpc->refId, PROC_FUNC_REQ); } else { @@ -148,7 +148,7 @@ static void dmProcessRpcMsg(SDnode *pDnode, SRpcMsg *pRpc, SEpSet *pEpSet) { _OVER: if (code == 0) { if (pWrapper != NULL && InParentProc(pWrapper->proc.ptype)) { - dTrace("msg:%p, freed in parent process", pMsg); + dTrace("msg:%p, is freed after push to cqueue", pMsg); taosFreeQitem(pMsg); rpcFreeCont(pRpc->pCont); }