enh: adjust log format

This commit is contained in:
Simon Guan 2025-02-26 19:15:35 +08:00
parent e314966cb9
commit 42e39a59df
19 changed files with 54 additions and 53 deletions

View File

@ -262,14 +262,14 @@ static void deregisterRequest(SRequestObj *pRequest) {
if ((pRequest->pQuery && pRequest->pQuery->pRoot && QUERY_NODE_VNODE_MODIFY_STMT == pRequest->pQuery->pRoot->type && if ((pRequest->pQuery && pRequest->pQuery->pRoot && QUERY_NODE_VNODE_MODIFY_STMT == pRequest->pQuery->pRoot->type &&
(0 == ((SVnodeModifyOpStmt *)pRequest->pQuery->pRoot)->sqlNodeType)) || (0 == ((SVnodeModifyOpStmt *)pRequest->pQuery->pRoot)->sqlNodeType)) ||
QUERY_NODE_VNODE_MODIFY_STMT == pRequest->stmtType) { QUERY_NODE_VNODE_MODIFY_STMT == pRequest->stmtType) {
tscDebug("req:0x%" PRIx64 ", insert duration %" PRId64 "us: parseCost:%" PRId64 "us, ctgCost:%" PRId64 tscDebug("req:0x%" PRIx64 ", insert duration:%" PRId64 "us, parseCost:%" PRId64 "us, ctgCost:%" PRId64
"us, analyseCost:%" PRId64 "us, planCost:%" PRId64 "us, exec:%" PRId64 "us", "us, analyseCost:%" PRId64 "us, planCost:%" PRId64 "us, exec:%" PRId64 "us",
pRequest->self, duration, pRequest->metric.parseCostUs, pRequest->metric.ctgCostUs, pRequest->self, duration, pRequest->metric.parseCostUs, pRequest->metric.ctgCostUs,
pRequest->metric.analyseCostUs, pRequest->metric.planCostUs, pRequest->metric.execCostUs); pRequest->metric.analyseCostUs, pRequest->metric.planCostUs, pRequest->metric.execCostUs);
(void)atomic_add_fetch_64((int64_t *)&pActivity->insertElapsedTime, duration); (void)atomic_add_fetch_64((int64_t *)&pActivity->insertElapsedTime, duration);
reqType = SLOW_LOG_TYPE_INSERT; reqType = SLOW_LOG_TYPE_INSERT;
} else if (QUERY_NODE_SELECT_STMT == pRequest->stmtType) { } else if (QUERY_NODE_SELECT_STMT == pRequest->stmtType) {
tscDebug("req:0x%" PRIx64 ", query duration %" PRId64 "us: parseCost:%" PRId64 "us, ctgCost:%" PRId64 tscDebug("req:0x%" PRIx64 ", query duration:%" PRId64 "us, parseCost:%" PRId64 "us, ctgCost:%" PRId64
"us, analyseCost:%" PRId64 "us, planCost:%" PRId64 "us, exec:%" PRId64 "us", "us, analyseCost:%" PRId64 "us, planCost:%" PRId64 "us, exec:%" PRId64 "us",
pRequest->self, duration, pRequest->metric.parseCostUs, pRequest->metric.ctgCostUs, pRequest->self, duration, pRequest->metric.parseCostUs, pRequest->metric.ctgCostUs,
pRequest->metric.analyseCostUs, pRequest->metric.planCostUs, pRequest->metric.execCostUs); pRequest->metric.analyseCostUs, pRequest->metric.planCostUs, pRequest->metric.execCostUs);

View File

@ -264,7 +264,7 @@ int32_t buildRequest(uint64_t connId, const char* sql, int sqlLen, void* param,
} }
} }
tscDebugL("req:0x%" PRIx64 ", SQL:%s, QID:0x%" PRIx64, (*pRequest)->self, (*pRequest)->sqlstr, (*pRequest)->requestId); tscDebugL("req:0x%" PRIx64 ", QID:0x%" PRIx64 ", build request", (*pRequest)->self, (*pRequest)->sqlstr, (*pRequest)->requestId);
return TSDB_CODE_SUCCESS; return TSDB_CODE_SUCCESS;
} }
@ -1030,7 +1030,7 @@ int32_t handleQueryExecRsp(SRequestObj* pRequest) {
break; break;
} }
default: default:
tscError("req: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); pRequest->requestId);
code = TSDB_CODE_APP_ERROR; code = TSDB_CODE_APP_ERROR;
} }
@ -1212,7 +1212,7 @@ void schedulerExecCb(SExecResult* pResult, void* param, int32_t code) {
pRequest->requestId); pRequest->requestId);
if (code != TSDB_CODE_SUCCESS && NEED_CLIENT_HANDLE_ERROR(code) && pRequest->sqlstr != NULL) { if (code != TSDB_CODE_SUCCESS && NEED_CLIENT_HANDLE_ERROR(code) && pRequest->sqlstr != NULL) {
tscDebug("re:0x%" PRIx64 ", client retry to handle the error, code:%s, tryCount:%d, QID:0x%" PRIx64, pRequest->self, tscDebug("req:0x%" PRIx64 ", client retry to handle the error, code:%s, tryCount:%d, QID:0x%" PRIx64, pRequest->self,
tstrerror(code), pRequest->retry, pRequest->requestId); tstrerror(code), pRequest->retry, pRequest->requestId);
if (TSDB_CODE_SUCCESS != removeMeta(pTscObj, pRequest->targetTableList, IS_VIEW_REQUEST(pRequest->type))) { if (TSDB_CODE_SUCCESS != removeMeta(pTscObj, pRequest->targetTableList, IS_VIEW_REQUEST(pRequest->type))) {
tscError("req: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);
@ -1221,7 +1221,7 @@ void schedulerExecCb(SExecResult* pResult, void* param, int32_t code) {
return; return;
} }
tscDebug("req:0x%" PRIx64 ", schedulerExecCb request type %s", pRequest->self, TMSG_INFO(pRequest->type)); tscTrace("req:0x%" PRIx64 ", scheduler exec cb, request type:%s", pRequest->self, TMSG_INFO(pRequest->type));
if (NEED_CLIENT_RM_TBLMETA_REQ(pRequest->type) && NULL == pRequest->body.resInfo.execRes.res) { 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))) { if (TSDB_CODE_SUCCESS != removeMeta(pTscObj, pRequest->targetTableList, IS_VIEW_REQUEST(pRequest->type))) {
tscError("req: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);
@ -2983,7 +2983,8 @@ TAOS_RES* taosQueryImpl(TAOS* taos, const char* sql, bool validateOnly, int8_t s
} }
taosMemoryFree(param); taosMemoryFree(param);
tscDebug("connObj:0x%" PRIx64 ", res:%p created, taos_query end with sql:%s", *(int64_t*)taos, pRequest, sql); tscDebug("connObj:0x%" PRIx64 ", res:%p created, taos_query end, affectRows:%" PRId64, *(int64_t*)taos, pRequest,
pRequest->body.resInfo.numOfRows);
return pRequest; return pRequest;
} }

View File

@ -539,7 +539,7 @@ void taos_free_result(TAOS_RES *res) {
if (TD_RES_QUERY(res)) { if (TD_RES_QUERY(res)) {
SRequestObj *pRequest = (SRequestObj *)res; SRequestObj *pRequest = (SRequestObj *)res;
tscDebug("QID:0x%" PRIx64 ", taos_free_result start to free query", pRequest->requestId); tscDebug("QID:0x%" PRIx64 ", call taos_free_result to free query", pRequest->requestId);
destroyRequest(pRequest); destroyRequest(pRequest);
return; return;
} }

View File

@ -1024,13 +1024,13 @@ int32_t tdProcessRSmaSubmit(SSma *pSma, int64_t version, void *pReq, void *pMsg,
STbUidStore uidStore = {0}; STbUidStore uidStore = {0};
if ((code = tdFetchSubmitReqSuids(pReq, &uidStore)) < 0) { if ((code = tdFetchSubmitReqSuids(pReq, &uidStore)) < 0) {
smaError("vgId:%d, failed to process rsma submit fetch suid since: %s", SMA_VID(pSma), tstrerror(code)); smaError("vgId:%d, failed to process rsma submit fetch suid since %s", SMA_VID(pSma), tstrerror(code));
goto _exit; goto _exit;
} }
if (uidStore.suid != 0) { if (uidStore.suid != 0) {
if ((code = tdExecuteRSmaAsync(pSma, version, pMsg, len, STREAM_INPUT__DATA_SUBMIT, uidStore.suid)) < 0) { if ((code = tdExecuteRSmaAsync(pSma, version, pMsg, len, STREAM_INPUT__DATA_SUBMIT, uidStore.suid)) < 0) {
smaError("vgId:%d, failed to process rsma submit exec 1 since: %s", SMA_VID(pSma), tstrerror(code)); smaError("vgId:%d, failed to process rsma submit exec 1 since %s", SMA_VID(pSma), tstrerror(code));
goto _exit; goto _exit;
} }
@ -1060,7 +1060,7 @@ int32_t tdProcessRSmaDelete(SSma *pSma, int64_t version, void *pReq, void *pMsg,
SDeleteRes *pDelRes = pReq; SDeleteRes *pDelRes = pReq;
if ((code = tdExecuteRSmaAsync(pSma, version, pMsg, len, STREAM_INPUT__REF_DATA_BLOCK, pDelRes->suid)) < 0) { if ((code = tdExecuteRSmaAsync(pSma, version, pMsg, len, STREAM_INPUT__REF_DATA_BLOCK, pDelRes->suid)) < 0) {
smaError("vgId:%d, failed to process rsma submit exec 1 since: %s", SMA_VID(pSma), tstrerror(code)); smaError("vgId:%d, failed to process rsma submit exec 1 since %s", SMA_VID(pSma), tstrerror(code));
goto _exit; goto _exit;
} }
_exit: _exit:

View File

@ -370,7 +370,7 @@ int32_t qBindStmtStbColsValue(void* pBlock, SArray* pCols, TAOS_MULTI_BIND* bind
code = tRowBuildFromBind(pBindInfos, boundInfo->numOfBound, colInOrder, *pTSchema, pCols, &pDataBlock->ordered, &pDataBlock->duplicateTs); code = tRowBuildFromBind(pBindInfos, boundInfo->numOfBound, colInOrder, *pTSchema, pCols, &pDataBlock->ordered, &pDataBlock->duplicateTs);
qDebug("stmt all %d columns bind %d rows data", boundInfo->numOfBound, rowNum); parserDebug("stmt all %d columns bind %d rows data", boundInfo->numOfBound, rowNum);
_return: _return:
@ -423,7 +423,7 @@ int32_t qBindStmtColsValue(void* pBlock, SArray* pCols, TAOS_MULTI_BIND* bind, c
} }
} }
qDebug("stmt all %d columns bind %d rows data", boundInfo->numOfBound, rowNum); parserDebug("stmt all %d columns bind %d rows data", boundInfo->numOfBound, rowNum);
_return: _return:
@ -472,7 +472,7 @@ int32_t qBindStmtSingleColValue(void* pBlock, SArray* pCols, TAOS_MULTI_BIND* bi
IS_VAR_DATA_TYPE(pColSchema->type) ? pColSchema->bytes - VARSTR_HEADER_SIZE : -1, IS_VAR_DATA_TYPE(pColSchema->type) ? pColSchema->bytes - VARSTR_HEADER_SIZE : -1,
initCtxAsText, checkWKB); initCtxAsText, checkWKB);
qDebug("stmt col %d bind %d rows data", colIdx, rowNum); parserDebug("stmt col %d bind %d rows data", colIdx, rowNum);
_return: _return:
@ -750,7 +750,7 @@ int32_t qBindStmtStbColsValue2(void* pBlock, SArray* pCols, TAOS_STMT2_BIND* bin
code = tRowBuildFromBind2(pBindInfos, boundInfo->numOfBound, colInOrder, *pTSchema, pCols, &pDataBlock->ordered, &pDataBlock->duplicateTs); code = tRowBuildFromBind2(pBindInfos, boundInfo->numOfBound, colInOrder, *pTSchema, pCols, &pDataBlock->ordered, &pDataBlock->duplicateTs);
qDebug("stmt all %d columns bind %d rows data", boundInfo->numOfBound, rowNum); parserDebug("stmt all %d columns bind %d rows data", boundInfo->numOfBound, rowNum);
_return: _return:
if (ncharBinds) { if (ncharBinds) {
@ -867,7 +867,7 @@ int32_t qBindStmtColsValue2(void* pBlock, SArray* pCols, TAOS_STMT2_BIND* bind,
} }
} }
qDebug("stmt2 all %d columns bind %d rows data as col format", boundInfo->numOfBound, rowNum); parserDebug("stmt2 all %d columns bind %d rows data as col format", boundInfo->numOfBound, rowNum);
_return: _return:
@ -916,7 +916,7 @@ int32_t qBindStmtSingleColValue2(void* pBlock, SArray* pCols, TAOS_STMT2_BIND* b
IS_VAR_DATA_TYPE(pColSchema->type) ? pColSchema->bytes - VARSTR_HEADER_SIZE : -1, IS_VAR_DATA_TYPE(pColSchema->type) ? pColSchema->bytes - VARSTR_HEADER_SIZE : -1,
initCtxAsText, checkWKB); initCtxAsText, checkWKB);
qDebug("stmt col %d bind %d rows data", colIdx, rowNum); parserDebug("stmt col %d bind %d rows data", colIdx, rowNum);
_return: _return:
@ -1096,7 +1096,7 @@ int32_t qResetStmtColumns(SArray* pCols, bool deepClear) {
for (int32_t i = 0; i < colNum; ++i) { for (int32_t i = 0; i < colNum; ++i) {
SColData* pCol = (SColData*)taosArrayGet(pCols, i); SColData* pCol = (SColData*)taosArrayGet(pCols, i);
if (pCol == NULL) { if (pCol == NULL) {
qError("qResetStmtColumns column is NULL"); parserError("qResetStmtColumns column is NULL");
return terrno; return terrno;
} }
if (deepClear) { if (deepClear) {
@ -1116,7 +1116,7 @@ int32_t qResetStmtDataBlock(STableDataCxt* block, bool deepClear) {
for (int32_t i = 0; i < colNum; ++i) { for (int32_t i = 0; i < colNum; ++i) {
SColData* pCol = (SColData*)taosArrayGet(pBlock->pData->aCol, i); SColData* pCol = (SColData*)taosArrayGet(pBlock->pData->aCol, i);
if (pCol == NULL) { if (pCol == NULL) {
qError("qResetStmtDataBlock column is NULL"); parserError("qResetStmtDataBlock column is NULL");
return terrno; return terrno;
} }
if (deepClear) { if (deepClear) {

View File

@ -298,7 +298,7 @@ static int32_t createTableDataCxt(STableMeta* pTableMeta, SVCreateTbReq** pCreat
} }
if (TSDB_CODE_SUCCESS == code) { if (TSDB_CODE_SUCCESS == code) {
*pOutput = pTableCxt; *pOutput = pTableCxt;
qDebug("uid:%" PRId64 ", create table data context, code:%d, vgId:%d", pTableMeta->uid, code, pTableMeta->vgId); parserDebug("uid:%" PRId64 ", create table data context, code:%d, vgId:%d", pTableMeta->uid, code, pTableMeta->vgId);
} else { } else {
insDestroyTableDataCxt(pTableCxt); insDestroyTableDataCxt(pTableCxt);
} }
@ -478,7 +478,7 @@ static int32_t fillVgroupDataCxt(STableDataCxt* pTableCxt, SVgroupDataCxt* pVgCx
taosMemoryFreeClear(pTableCxt->pData); taosMemoryFreeClear(pTableCxt->pData);
} }
qDebug("uid:%" PRId64 ", add table data context to vgId:%d", pTableCxt->pMeta->uid, pVgCxt->vgId); parserDebug("uid:%" PRId64 ", add table data context to vgId:%d", pTableCxt->pMeta->uid, pVgCxt->vgId);
return code; return code;
} }
@ -760,7 +760,7 @@ int32_t insMergeTableDataCxt(SHashObj* pTableHash, SArray** pVgDataBlocks, bool
// skip the table has no data to insert // skip the table has no data to insert
// eg: import a csv without valid data // eg: import a csv without valid data
// if (0 == taosArrayGetSize(pTableCxt->pData->aRowP)) { // if (0 == taosArrayGetSize(pTableCxt->pData->aRowP)) {
// qWarn("no row in tableDataCxt uid:%" PRId64 " ", pTableCxt->pMeta->uid); // parserWarn("no row in tableDataCxt uid:%" PRId64 " ", pTableCxt->pMeta->uid);
// p = taosHashIterate(pTableHash, p); // p = taosHashIterate(pTableHash, p);
// continue; // continue;
// } // }

View File

@ -7015,7 +7015,7 @@ static int32_t setEqualTbnameTableVgroups(STranslateContext* pCxt, SSelectStmt*
bool stableQuery = false; bool stableQuery = false;
SEqCondTbNameTableInfo* pInfo = NULL; SEqCondTbNameTableInfo* pInfo = NULL;
qDebug("start to update stable vg for tbname optimize, aTableNum:%d", aTableNum); parserDebug("start to update stable vg for tbname optimize, aTableNum:%d", aTableNum);
for (int i = 0; i < aTableNum; ++i) { for (int i = 0; i < aTableNum; ++i) {
pInfo = taosArrayGet(aTables, i); pInfo = taosArrayGet(aTables, i);
int32_t numOfVgs = pInfo->pRealTable->pVgroupList->numOfVgroups; int32_t numOfVgs = pInfo->pRealTable->pVgroupList->numOfVgroups;
@ -7084,7 +7084,7 @@ static int32_t setEqualTbnameTableVgroups(STranslateContext* pCxt, SSelectStmt*
} }
} }
qDebug("before ctbname optimize, code:%d, aTableNum:%d, nTbls:%d, stableQuery:%d", code, aTableNum, nTbls, parserDebug("before ctbname optimize, code:%d, aTableNum:%d, nTbls:%d, stableQuery:%d", code, aTableNum, nTbls,
stableQuery); stableQuery);
if (TSDB_CODE_SUCCESS == code && 1 == aTableNum && 1 == nTbls && stableQuery && NULL == pInfo->pRealTable->pTsmas) { if (TSDB_CODE_SUCCESS == code && 1 == aTableNum && 1 == nTbls && stableQuery && NULL == pInfo->pRealTable->pTsmas) {
@ -13001,7 +13001,7 @@ static int32_t readFromFile(char* pName, int32_t* len, char** buf) {
int64_t s = taosReadFile(tfile, *buf, *len); int64_t s = taosReadFile(tfile, *buf, *len);
if (s != *len) { if (s != *len) {
int32_t code = taosCloseFile(&tfile); int32_t code = taosCloseFile(&tfile);
qError("failed to close file: %s in %s:%d, err: %s", pName, __func__, __LINE__, tstrerror(code)); parserError("failed to close file: %s in %s:%d, err: %s", pName, __func__, __LINE__, tstrerror(code));
taosMemoryFreeClear(*buf); taosMemoryFreeClear(*buf);
return TSDB_CODE_APP_ERROR; return TSDB_CODE_APP_ERROR;
} }
@ -15835,7 +15835,7 @@ int32_t serializeVgroupsCreateTableBatch(SHashObj* pVgroupHashmap, SArray** pOut
code = serializeVgroupCreateTableBatch(pTbBatch, pBufArray); code = serializeVgroupCreateTableBatch(pTbBatch, pBufArray);
if (TSDB_CODE_SUCCESS != code) { if (TSDB_CODE_SUCCESS != code) {
qError("failed to serialize create table batch msg, since:%s", tstrerror(code)); parserError("failed to serialize create table batch msg, since:%s", tstrerror(code));
taosHashCancelIterate(pVgroupHashmap, pTbBatch); taosHashCancelIterate(pVgroupHashmap, pTbBatch);
break; break;
} }
@ -15914,7 +15914,7 @@ static int32_t rewriteCreateTableFromFile(STranslateContext* pCxt, SQuery* pQuer
taosHashClear(pModifyStmt->pVgroupsHashObj); taosHashClear(pModifyStmt->pVgroupsHashObj);
if (TSDB_CODE_SUCCESS != code) { if (TSDB_CODE_SUCCESS != code) {
if (TSDB_CODE_INVALID_MSG_LEN == code) { if (TSDB_CODE_INVALID_MSG_LEN == code) {
qError("maxInsertBatchRows may need to be reduced, current:%d", tsMaxInsertBatchRows); parserError("maxInsertBatchRows may need to be reduced, current:%d", tsMaxInsertBatchRows);
} }
taosHashCleanup(pModifyStmt->pVgroupsHashObj); taosHashCleanup(pModifyStmt->pVgroupsHashObj);
return code; return code;

View File

@ -343,7 +343,7 @@ void destroyQueryExecRes(SExecResult* pRes) {
break; break;
} }
default: default:
qError("invalid exec result for request type %d", pRes->msgType); qError("invalid exec result for request type:%d", pRes->msgType);
} }
} }
// clang-format on // clang-format on

View File

@ -171,7 +171,7 @@ void schedulerFreeJob(int64_t *jobId, int32_t errCode) {
return; return;
} }
SCH_JOB_DLOG("start to free job 0x%" PRIx64 ", code:%s", *jobId, tstrerror(errCode)); SCH_JOB_DLOG("jobId:0x%" PRIx64 ", start to free, code:%s", *jobId, tstrerror(errCode));
(void)schHandleJobDrop(pJob, errCode); // ignore any error (void)schHandleJobDrop(pJob, errCode); // ignore any error
int32_t released = false; int32_t released = false;