enh: adjust log format

This commit is contained in:
Simon Guan 2025-02-26 15:25:38 +08:00
parent e97b5cf4c1
commit 92f8f3690d
4 changed files with 39 additions and 41 deletions

View File

@ -93,8 +93,7 @@ static int32_t registerRequest(SRequestObj *pRequest, STscObj *pTscObj) {
int32_t total = atomic_add_fetch_64((int64_t *)&pSummary->totalRequests, 1);
int32_t currentInst = atomic_add_fetch_64((int64_t *)&pSummary->currentRequests, 1);
tscDebug("0x%" PRIx64 " new Request from connObj:0x%" PRIx64
", current:%d, app current:%d, total:%d, QID:0x%" PRIx64,
tscDebug("req:0x%" PRIx64 ", new from connObj:0x%" PRIx64 ", current:%d, app current:%d, total:%d, QID:0x%" PRIx64,
pRequest->self, pRequest->pTscObj->id, num, currentInst, total, pRequest->requestId);
}
@ -255,9 +254,8 @@ static void deregisterRequest(SRequestObj *pRequest) {
int32_t reqType = SLOW_LOG_TYPE_OTHERS;
int64_t duration = taosGetTimestampUs() - pRequest->metric.start;
tscDebug("0x%" PRIx64 " free Request from connObj:0x%" PRIx64 ", QID:0x%" PRIx64
" elapsed:%.2f ms, "
"current:%d, app current:%d",
tscDebug("req:0x%" PRIx64 ", free from connObj:0x%" PRIx64 ", QID:0x%" PRIx64
" elapsed:%.2f ms, current:%d, app current:%d",
pRequest->self, pTscObj->id, pRequest->requestId, duration / 1000.0, num, currentInst);
if (TSDB_CODE_SUCCESS == nodesSimAcquireAllocator(pRequest->allocatorRefId)) {

View File

@ -227,7 +227,7 @@ int32_t buildRequest(uint64_t connId, const char* sql, int sqlLen, void* param,
(*pRequest)->sqlstr = taosMemoryMalloc(sqlLen + 1);
if ((*pRequest)->sqlstr == NULL) {
tscError("0x%" PRIx64 " failed to prepare sql string buffer, %s", (*pRequest)->self, sql);
tscError("req:0x%" PRIx64 ", failed to prepare sql string buffer, %s", (*pRequest)->self, sql);
destroyRequest(*pRequest);
*pRequest = NULL;
return terrno;
@ -245,7 +245,7 @@ int32_t buildRequest(uint64_t connId, const char* sql, int sqlLen, void* param,
int32_t err = taosHashPut(pTscObj->pRequests, &(*pRequest)->self, sizeof((*pRequest)->self), &(*pRequest)->self,
sizeof((*pRequest)->self));
if (err) {
tscError("%" PRId64 " failed to add to request container, QID:0x%" PRIx64 ", conn:%" PRId64 ", %s",
tscError("req:0x%" PRId64 ", failed to add to request container, QID:0x%" PRIx64 ", conn:%" PRId64 ", %s",
(*pRequest)->self, (*pRequest)->requestId, pTscObj->id, sql);
destroyRequest(*pRequest);
*pRequest = NULL;
@ -256,7 +256,7 @@ int32_t buildRequest(uint64_t connId, const char* sql, int sqlLen, void* param,
if (tsQueryUseNodeAllocator && !qIsInsertValuesSql((*pRequest)->sqlstr, (*pRequest)->sqlLen)) {
if (TSDB_CODE_SUCCESS !=
nodesCreateAllocator((*pRequest)->requestId, tsQueryNodeChunkSize, &((*pRequest)->allocatorRefId))) {
tscError("%" PRId64 " failed to create node allocator, QID:0x%" PRIx64 ", conn:%" PRId64 ", %s", (*pRequest)->self,
tscError("req:0x%" PRId64 ", failed to create node allocator, QID:0x%" PRIx64 ", conn:%" PRId64 ", %s", (*pRequest)->self,
(*pRequest)->requestId, pTscObj->id, sql);
destroyRequest(*pRequest);
*pRequest = NULL;
@ -264,7 +264,7 @@ int32_t buildRequest(uint64_t connId, const char* sql, int sqlLen, void* param,
}
}
tscDebugL("0x%" PRIx64 " SQL:%s, QID:0x%" PRIx64, (*pRequest)->self, (*pRequest)->sqlstr, (*pRequest)->requestId);
tscDebugL("req:0x%" PRIx64 ", SQL:%s, QID:0x%" PRIx64, (*pRequest)->self, (*pRequest)->sqlstr, (*pRequest)->requestId);
return TSDB_CODE_SUCCESS;
}
@ -381,10 +381,10 @@ void asyncExecLocalCmd(SRequestObj* pRequest, SQuery* pQuery) {
if (pRequest->code != TSDB_CODE_SUCCESS) {
pResultInfo->numOfRows = 0;
tscError("0x%" PRIx64 " fetch results failed, code:%s, QID:0x%" PRIx64, pRequest->self, tstrerror(code),
tscError("req:0x%" PRIx64 ", fetch results failed, code:%s, QID:0x%" PRIx64, pRequest->self, tstrerror(code),
pRequest->requestId);
} else {
tscDebug("0x%" PRIx64 " fetch results, numOfRows:%" PRId64 " total Rows:%" PRId64 ", complete:%d, QID:0x%" PRIx64,
tscDebug("req:0x%" PRIx64 ", fetch results, numOfRows:%" PRId64 " total Rows:%" PRId64 ", complete:%d, QID:0x%" PRIx64,
pRequest->self, pResultInfo->numOfRows, pResultInfo->totalRows, pResultInfo->completed,
pRequest->requestId);
}
@ -1030,7 +1030,7 @@ int32_t handleQueryExecRsp(SRequestObj* pRequest) {
break;
}
default:
tscError("0x%" PRIx64 ", invalid exec result for request type %d, QID:0x%" PRIx64, pRequest->self, pRequest->type,
tscError("req:0x%" PRIx64 ", invalid exec result for request type %d, QID:0x%" PRIx64, pRequest->self, pRequest->type,
pRequest->requestId);
code = TSDB_CODE_APP_ERROR;
}
@ -1075,7 +1075,7 @@ void returnToUser(SRequestObj* pRequest) {
(void)releaseRequest(pRequest->relation.userRefId);
return;
} else {
tscError("0x%" PRIx64 ", user ref 0x%" PRIx64 " is not there, QID:0x%" PRIx64, pRequest->self,
tscError("req:0x%" PRIx64 ", user ref 0x%" PRIx64 " is not there, QID:0x%" PRIx64, pRequest->self,
pRequest->relation.userRefId, pRequest->requestId);
}
}
@ -1146,7 +1146,7 @@ void postSubQueryFetchCb(void* param, TAOS_RES* res, int32_t rowNum) {
SSDataBlock* pBlock = NULL;
pRequest->code = createResultBlock(res, rowNum, &pBlock);
if (TSDB_CODE_SUCCESS != pRequest->code) {
tscError("0x%" PRIx64 ", create result block failed, QID:0x%" PRIx64 " %s", pRequest->self, pRequest->requestId,
tscError("req:0x%" PRIx64 ", create result block failed, QID:0x%" PRIx64 " %s", pRequest->self, pRequest->requestId,
tstrerror(pRequest->code));
returnToUser(pRequest);
return;
@ -1157,7 +1157,7 @@ void postSubQueryFetchCb(void* param, TAOS_RES* res, int32_t rowNum) {
continuePostSubQuery(pNextReq, pBlock);
(void)releaseRequest(pRequest->relation.nextRefId);
} else {
tscError("0x%" PRIx64 ", next req ref 0x%" PRIx64 " is not there, QID:0x%" PRIx64, pRequest->self,
tscError("req:0x%" PRIx64 ", next req ref 0x%" PRIx64 " is not there, QID:0x%" PRIx64, pRequest->self,
pRequest->relation.nextRefId, pRequest->requestId);
}
@ -1176,7 +1176,7 @@ void handlePostSubQuery(SSqlCallbackWrapper* pWrapper) {
continuePostSubQuery(pNextReq, NULL);
(void)releaseRequest(pRequest->relation.nextRefId);
} else {
tscError("0x%" PRIx64 ", next req ref 0x%" PRIx64 " is not there, QID:0x%" PRIx64, pRequest->self,
tscError("req:0x%" PRIx64 ", next req ref 0x%" PRIx64 " is not there, QID:0x%" PRIx64, pRequest->self,
pRequest->relation.nextRefId, pRequest->requestId);
}
}
@ -1208,14 +1208,14 @@ void schedulerExecCb(SExecResult* pResult, void* param, int32_t code) {
}
taosMemoryFree(pResult);
tscDebug("0x%" PRIx64 " enter scheduler exec cb, code:%s, QID:0x%" PRIx64, pRequest->self, tstrerror(code),
tscDebug("req:0x%" PRIx64 ", enter scheduler exec cb, code:%s, QID:0x%" PRIx64, pRequest->self, tstrerror(code),
pRequest->requestId);
if (code != TSDB_CODE_SUCCESS && NEED_CLIENT_HANDLE_ERROR(code) && pRequest->sqlstr != NULL) {
tscDebug("0x%" PRIx64 " client retry to handle the error, code:%s, tryCount:%d, QID:0x%" PRIx64, pRequest->self,
tscDebug("re:0x%" PRIx64 ", client retry to handle the error, code:%s, tryCount:%d, QID:0x%" PRIx64, pRequest->self,
tstrerror(code), pRequest->retry, pRequest->requestId);
if (TSDB_CODE_SUCCESS != removeMeta(pTscObj, pRequest->targetTableList, IS_VIEW_REQUEST(pRequest->type))) {
tscError("0x%" PRIx64 " remove meta failed, QID:0x%" PRIx64, pRequest->self, pRequest->requestId);
tscError("req:0x%" PRIx64 ", remove meta failed, QID:0x%" PRIx64, pRequest->self, pRequest->requestId);
}
restartAsyncQuery(pRequest, code);
return;
@ -1224,7 +1224,7 @@ void schedulerExecCb(SExecResult* pResult, void* param, int32_t code) {
tscDebug("schedulerExecCb request type %s", TMSG_INFO(pRequest->type));
if (NEED_CLIENT_RM_TBLMETA_REQ(pRequest->type) && NULL == pRequest->body.resInfo.execRes.res) {
if (TSDB_CODE_SUCCESS != removeMeta(pTscObj, pRequest->targetTableList, IS_VIEW_REQUEST(pRequest->type))) {
tscError("0x%" PRIx64 " remove meta failed, QID:0x%" PRIx64, pRequest->self, pRequest->requestId);
tscError("req:0x%" PRIx64 ", remove meta failed, QID:0x%" PRIx64, pRequest->self, pRequest->requestId);
}
}
@ -1322,7 +1322,7 @@ void launchQueryImpl(SRequestObj* pRequest, SQuery* pQuery, bool keepQuery, void
if (NEED_CLIENT_RM_TBLMETA_REQ(pRequest->type) && NULL == pRequest->body.resInfo.execRes.res) {
int ret = removeMeta(pRequest->pTscObj, pRequest->targetTableList, IS_VIEW_REQUEST(pRequest->type));
if (TSDB_CODE_SUCCESS != ret) {
tscError("0x%" PRIx64 " remove meta failed,code:%d, QID:0x%" PRIx64, pRequest->self, ret, pRequest->requestId);
tscError("req:0x%" PRIx64 ", remove meta failed,code:%d, QID:0x%" PRIx64, pRequest->self, ret, pRequest->requestId);
}
}
@ -1370,7 +1370,7 @@ static int32_t asyncExecSchQuery(SRequestObj* pRequest, SQuery* pQuery, SMetaDat
code = qCreateQueryPlan(&cxt, &pDag, pMnodeList);
}
if (code) {
tscError("0x%" PRIx64 " failed to create query plan, code:%s 0x%" PRIx64, pRequest->self, tstrerror(code),
tscError("req:0x%" PRIx64 ", failed to create query plan, code:%s 0x%" PRIx64, pRequest->self, tstrerror(code),
pRequest->requestId);
} else {
pRequest->body.subplanNum = pDag->numOfSubplans;
@ -1414,7 +1414,7 @@ static int32_t asyncExecSchQuery(SRequestObj* pRequest, SQuery* pQuery, SMetaDat
taosArrayDestroy(pNodeList);
} else {
qDestroyQueryPlan(pDag);
tscDebug("0x%" PRIx64 " plan not executed, code:%s 0x%" PRIx64, pRequest->self, tstrerror(code),
tscDebug("req:0x%" PRIx64 ", plan not executed, code:%s 0x%" PRIx64, pRequest->self, tstrerror(code),
pRequest->requestId);
destorySqlCallbackWrapper(pWrapper);
pRequest->pWrapper = NULL;
@ -1472,7 +1472,7 @@ void launchAsyncQuery(SRequestObj* pRequest, SQuery* pQuery, SMetaData* pResultM
doRequestCallback(pRequest, 0);
break;
default:
tscError("0x%" PRIx64 " invalid execMode %d", pRequest->self, pQuery->execMode);
tscError("req:0x%" PRIx64 ", invalid execMode %d", pRequest->self, pQuery->execMode);
doRequestCallback(pRequest, -1);
break;
}
@ -1796,7 +1796,7 @@ int32_t doProcessMsgFromServerImpl(SRpcMsg* pMsg, SEpSet* pEpSet) {
SRequestObj* pRequest = (SRequestObj*)taosAcquireRef(clientReqRefPool, pSendInfo->requestObjRefId);
if (pRequest) {
if (pRequest->self != pSendInfo->requestObjRefId) {
tscError("doProcessMsgFromServer pRequest->self:%" PRId64 " != pSendInfo->requestObjRefId:%" PRId64,
tscError("doProcessMsgFromServer req:0x%" PRId64 " != pSendInfo->requestObjRefId:0x%" PRId64,
pRequest->self, pSendInfo->requestObjRefId);
if (TSDB_CODE_SUCCESS != taosReleaseRef(clientReqRefPool, pSendInfo->requestObjRefId)) {
@ -2000,7 +2000,7 @@ void* doFetchRows(SRequestObj* pRequest, bool setupOneRowPtr, bool convertUcs4)
return NULL;
}
tscDebug("0x%" PRIx64 " fetch results, numOfRows:%" PRId64 " total Rows:%" PRId64 ", complete:%d, QID:0x%" PRIx64,
tscDebug("req:0x%" PRIx64 ", fetch results, numOfRows:%" PRId64 " total Rows:%" PRId64 ", complete:%d, QID:0x%" PRIx64,
pRequest->self, pResInfo->numOfRows, pResInfo->totalRows, pResInfo->completed, pRequest->requestId);
STscObj* pTscObj = pRequest->pTscObj;
@ -2952,7 +2952,7 @@ TAOS_RES* taosQueryImpl(TAOS* taos, const char* sql, bool validateOnly, int8_t s
return NULL;
}
tscDebug("taos_query start with sql:%s", sql);
tscDebug("connObj:0x%" PRIx64 ", taos_query start with sql:%s", *(int64_t*)taos, sql);
SSyncQueryParam* param = taosMemoryCalloc(1, sizeof(SSyncQueryParam));
if (NULL == param) {
@ -3024,7 +3024,7 @@ static void fetchCallback(void* pResult, void* param, int32_t code) {
SReqResultInfo* pResultInfo = &pRequest->body.resInfo;
tscDebug("0x%" PRIx64 " enter scheduler fetch cb, code:%d - %s, QID:0x%" PRIx64, pRequest->self, code, tstrerror(code),
tscDebug("req:0x%" PRIx64 ", enter scheduler fetch cb, code:%d - %s, QID:0x%" PRIx64, pRequest->self, code, tstrerror(code),
pRequest->requestId);
pResultInfo->pData = pResult;
@ -3047,10 +3047,10 @@ static void fetchCallback(void* pResult, void* param, int32_t code) {
setQueryResultFromRsp(pResultInfo, (const SRetrieveTableRsp*)pResultInfo->pData, pResultInfo->convertUcs4);
if (pRequest->code != TSDB_CODE_SUCCESS) {
pResultInfo->numOfRows = 0;
tscError("0x%" PRIx64 " fetch results failed, code:%s, QID:0x%" PRIx64, pRequest->self, tstrerror(pRequest->code),
tscError("req:0x%" PRIx64 ", fetch results failed, code:%s, QID:0x%" PRIx64, pRequest->self, tstrerror(pRequest->code),
pRequest->requestId);
} else {
tscDebug("0x%" PRIx64 " fetch results, numOfRows:%" PRId64 " total Rows:%" PRId64 ", complete:%d, QID:0x%" PRIx64,
tscDebug("req:0x%" PRIx64 ", fetch results, numOfRows:%" PRId64 " total Rows:%" PRId64 ", complete:%d, QID:0x%" PRIx64,
pRequest->self, pResultInfo->numOfRows, pResultInfo->totalRows, pResultInfo->completed,
pRequest->requestId);

View File

@ -1157,7 +1157,7 @@ static void doAsyncQueryFromAnalyse(SMetaData *pResultMeta, void *param, int32_t
SRequestObj *pRequest = pWrapper->pRequest;
SQuery *pQuery = pRequest->pQuery;
qDebug("0x%" PRIx64 " start to semantic analysis, QID:0x%" PRIx64, pRequest->self, pRequest->requestId);
qDebug("req:0x%" PRIx64 ", start to semantic analysis, QID:0x%" PRIx64, pRequest->self, pRequest->requestId);
int64_t analyseStart = taosGetTimestampUs();
pRequest->metric.ctgCostUs = analyseStart - pRequest->metric.ctgStart;
@ -1276,14 +1276,14 @@ void handleQueryAnslyseRes(SSqlCallbackWrapper *pWrapper, SMetaData *pResultMeta
pRequest->pQuery = NULL;
if (NEED_CLIENT_HANDLE_ERROR(code)) {
tscDebug("0x%" PRIx64 " client retry to handle the error, code:%d - %s, tryCount:%d, QID:0x%" PRIx64,
tscDebug("req:0x%" PRIx64 ", client retry to handle the error, code:%d - %s, tryCount:%d, QID:0x%" PRIx64,
pRequest->self, code, tstrerror(code), pRequest->retry, pRequest->requestId);
restartAsyncQuery(pRequest, code);
return;
}
// return to app directly
tscError("0x%" PRIx64 " error occurs, code:%s, return to user app, QID:0x%" PRIx64, pRequest->self, tstrerror(code),
tscError("req:0x%" PRIx64 ", error occurs, code:%s, return to user app, QID:0x%" PRIx64, pRequest->self, tstrerror(code),
pRequest->requestId);
pRequest->code = code;
returnToUser(pRequest);
@ -1333,7 +1333,7 @@ static void doAsyncQueryFromParse(SMetaData *pResultMeta, void *param, int32_t c
SQuery *pQuery = pRequest->pQuery;
pRequest->metric.ctgCostUs += taosGetTimestampUs() - pRequest->metric.ctgStart;
qDebug("0x%" PRIx64 " start to continue parse, QID:0x%" PRIx64 ", code:%s", pRequest->self, pRequest->requestId,
qDebug("req:0x%" PRIx64 ", start to continue parse, QID:0x%" PRIx64 ", code:%s", pRequest->self, pRequest->requestId,
tstrerror(code));
if (code == TSDB_CODE_SUCCESS) {
@ -1346,7 +1346,7 @@ static void doAsyncQueryFromParse(SMetaData *pResultMeta, void *param, int32_t c
}
if (TSDB_CODE_SUCCESS != code) {
tscError("0x%" PRIx64 " error happens, code:%d - %s, QID:0x%" PRIx64, pWrapper->pRequest->self, code,
tscError("req:0x%" PRIx64 ", error happens, code:%d - %s, QID:0x%" PRIx64, pWrapper->pRequest->self, code,
tstrerror(code), pWrapper->pRequest->requestId);
destorySqlCallbackWrapper(pWrapper);
pRequest->pWrapper = NULL;
@ -1363,7 +1363,7 @@ void continueInsertFromCsv(SSqlCallbackWrapper *pWrapper, SRequestObj *pRequest)
}
if (TSDB_CODE_SUCCESS != code) {
tscError("0x%" PRIx64 " error happens, code:%d - %s, QID:0x%" PRIx64, pWrapper->pRequest->self, code,
tscError("req:0x%" PRIx64 ", error happens, code:%d - %s, QID:0x%" PRIx64, pWrapper->pRequest->self, code,
tstrerror(code), pWrapper->pRequest->requestId);
destorySqlCallbackWrapper(pWrapper);
pRequest->pWrapper = NULL;
@ -1484,7 +1484,7 @@ void doAsyncQuery(SRequestObj *pRequest, bool updateMetaForce) {
}
if (TSDB_CODE_SUCCESS != code) {
tscError("0x%" PRIx64 " error happens, code:%d - %s, QID:0x%" PRIx64, pRequest->self, code, tstrerror(code),
tscError("req:0x%" PRIx64 ", error happens, code:%d - %s, QID:0x%" PRIx64, pRequest->self, code, tstrerror(code),
pRequest->requestId);
destorySqlCallbackWrapper(pWrapper);
pRequest->pWrapper = NULL;
@ -1492,11 +1492,11 @@ void doAsyncQuery(SRequestObj *pRequest, bool updateMetaForce) {
pRequest->pQuery = NULL;
if (NEED_CLIENT_HANDLE_ERROR(code)) {
tscDebug("0x%" PRIx64 " client retry to handle the error, code:%d - %s, tryCount:%d, QID:0x%" PRIx64,
tscDebug("req:0x%" PRIx64 ", client retry to handle the error, code:%d - %s, tryCount:%d, QID:0x%" PRIx64,
pRequest->self, code, tstrerror(code), pRequest->retry, pRequest->requestId);
code = refreshMeta(pRequest->pTscObj, pRequest);
if (code != 0) {
tscWarn("0x%" PRIx64 " refresh meta failed, code:%d - %s, QID:0x%" PRIx64, pRequest->self, code, tstrerror(code),
tscWarn("req:0x%" PRIx64 ", refresh meta failed, code:%d - %s, QID:0x%" PRIx64, pRequest->self, code, tstrerror(code),
pRequest->requestId);
}
pRequest->prevCode = code;
@ -1511,7 +1511,7 @@ void doAsyncQuery(SRequestObj *pRequest, bool updateMetaForce) {
}
void restartAsyncQuery(SRequestObj *pRequest, int32_t code) {
tscInfo("restart request: %s p: %p", pRequest->sqlstr, pRequest);
tscInfo("restart request:%s p:%p", pRequest->sqlstr, pRequest);
SRequestObj *pUserReq = pRequest;
(void)acquireRequest(pRequest->self);
while (pUserReq) {

View File

@ -917,7 +917,7 @@ int32_t catalogGetHandle(int64_t clusterId, SCatalog** catalogHandle) {
if (ctg && (*ctg)) {
*catalogHandle = *ctg;
CTG_STAT_HIT_INC(CTG_CI_CLUSTER, 1);
qDebug("CTG:%p, get catalog handle from cache, clusterId:0x%" PRIx64, *ctg, clusterId);
qDebug("CTG:%p get catalog handle from cache, clusterId:0x%" PRIx64, *ctg, clusterId);
CTG_API_LEAVE(TSDB_CODE_SUCCESS);
}