[TD-526] change sdb log

documentation/tdenginedocs-cn/administrator/index.html

@@ -55,7 +55,7 @@
 <li>enableMonitor: 系统监测标志位，0：关闭，1：打开</li>
 <li>logDir: 日志文件目录，缺省是/var/log/taos</li>
 <li>numOfLogLines：日志文件的最大行数</li>
-<li>debugFlag: 系统debug日志开关，131：仅错误和报警信息，135：所有</li>
+<li>debugFlag: 系统debug日志开关，131：仅错误和报警信息，135：调试信息，151：非常详细的调试信息</li>
 </ul>
 <p>不同应用场景的数据往往具有不同的数据特征，比如保留天数、副本数、采集频次、记录大小、采集点的数量、压缩等都可完全不同。为获得在存储上的最高效率，TDengine提供如下存储相关的系统配置参数：</p>
 <ul>

src/common/inc/tglobal.h

@@ -160,6 +160,7 @@ extern int32_t uDebugFlag;
 extern int32_t rpcDebugFlag;
 extern int32_t odbcDebugFlag;
 extern int32_t qDebugFlag;
+extern int32_t wDebugFlag;
 extern int32_t debugFlag;
 
 #define NEEDTO_COMPRESSS_MSG(size) (tsCompressMsgSize != -1 && (size) > tsCompressMsgSize)

src/common/src/tglobal.c

@@ -194,6 +194,7 @@ int32_t rpcDebugFlag = 135;
 int32_t uDebugFlag = 131;
 int32_t debugFlag = 131;
 int32_t sDebugFlag = 135;
+int32_t wDebugFlag = 135;
 int32_t tsdbDebugFlag = 135;
 
 static pthread_once_t tsInitGlobalCfgOnce = PTHREAD_ONCE_INIT;
@@ -213,6 +214,7 @@ void taosSetAllDebugFlag() {
     rpcDebugFlag = debugFlag;
     uDebugFlag = debugFlag;
     sDebugFlag = debugFlag;
+    wDebugFlag = debugFlag;
     tsdbDebugFlag = debugFlag;
     qDebugFlag = debugFlag;    
   }
@@ -977,6 +979,17 @@ static void doInitGlobalConfig() {
   cfg.unitType = TAOS_CFG_UTYPE_NONE;
   taosInitConfigOption(cfg);
 
+  cfg.option = "wDebugFlag";
+  cfg.ptr = &wDebugFlag;
+  cfg.valType = TAOS_CFG_VTYPE_INT32;
+  cfg.cfgType = TSDB_CFG_CTYPE_B_CONFIG | TSDB_CFG_CTYPE_B_LOG;
+  cfg.minValue = 0;
+  cfg.maxValue = 255;
+  cfg.ptrLength = 0;
+  cfg.unitType = TAOS_CFG_UTYPE_NONE;
+  taosInitConfigOption(cfg);
+
+
   cfg.option = "sdbDebugFlag";
   cfg.ptr = &sdbDebugFlag;
   cfg.valType = TAOS_CFG_VTYPE_INT32;

src/mnode/src/mnodeSdb.c

@@ -181,7 +181,7 @@ static int32_t sdbInitWal() {
     return -1;
   }
 
-  sdbDebug("open sdb wal for restore");
+  sdbInfo("open sdb wal for restore");
   walRestore(tsSdbObj.wal, NULL, sdbWrite);
   return 0;
 }
@@ -201,7 +201,7 @@ static void sdbRestoreTables() {
     sdbDebug("table:%s, is restored, numOfRows:%" PRId64, pTable->tableName, pTable->numOfRows);
   }
 
-  sdbDebug("sdb is restored, version:%" PRId64 " totalRows:%d numOfTables:%d", tsSdbObj.version, totalRows, numOfTables);
+  sdbInfo("sdb is restored, version:%" PRId64 " totalRows:%d numOfTables:%d", tsSdbObj.version, totalRows, numOfTables);
 }
 
 void sdbUpdateMnodeRoles() {
@@ -388,9 +388,7 @@ void sdbIncRef(void *handle, void *pObj) {
   SSdbTable *pTable = handle;
   int32_t *  pRefCount = (int32_t *)(pObj + pTable->refCountPos);
   atomic_add_fetch_32(pRefCount, 1);
-  if (0 && (pTable->tableId == SDB_TABLE_CTABLE || pTable->tableId == SDB_TABLE_DB)) {
-    sdbDebug("add ref to table:%s record:%p:%s:%d", pTable->tableName, pObj, sdbGetKeyStrFromObj(pTable, pObj), *pRefCount);
-  }
+  sdbTrace("add ref to table:%s record:%p:%s:%d", pTable->tableName, pObj, sdbGetKeyStrFromObj(pTable, pObj), *pRefCount);
 }
 
 void sdbDecRef(void *handle, void *pObj) {
@@ -399,13 +397,11 @@ void sdbDecRef(void *handle, void *pObj) {
   SSdbTable *pTable = handle;
   int32_t *  pRefCount = (int32_t *)(pObj + pTable->refCountPos);
   int32_t    refCount = atomic_sub_fetch_32(pRefCount, 1);
-  if (0 && (pTable->tableId == SDB_TABLE_CTABLE || pTable->tableId == SDB_TABLE_DB)) {
-    sdbDebug("def ref of table:%s record:%p:%s:%d", pTable->tableName, pObj, sdbGetKeyStrFromObj(pTable, pObj), *pRefCount);
-  }
+  sdbTrace("def ref of table:%s record:%p:%s:%d", pTable->tableName, pObj, sdbGetKeyStrFromObj(pTable, pObj), *pRefCount);
 
   int8_t *updateEnd = pObj + pTable->refCountPos - 1;
   if (refCount <= 0 && *updateEnd) {
-    sdbDebug("table:%s, record:%p:%s:%d is destroyed", pTable->tableName, pObj, sdbGetKeyStrFromObj(pTable, pObj), *pRefCount);
+    sdbTrace("table:%s, record:%p:%s:%d is destroyed", pTable->tableName, pObj, sdbGetKeyStrFromObj(pTable, pObj), *pRefCount);
     SSdbOper oper = {.pObj = pObj};
     (*pTable->destroyFp)(&oper);
   }
@@ -551,7 +547,7 @@ static int sdbWrite(void *param, void *data, int type) {
 
   // from app, oper is created
   if (pOper != NULL) {
-    sdbDebug("record from app is disposed, table:%s action:%s record:%s version:%" PRIu64 " result:%s",
+    sdbTrace("record from app is disposed, table:%s action:%s record:%s version:%" PRIu64 " result:%s",
              pTable->tableName, sdbGetActionStr(action), sdbGetKeyStr(pTable, pHead->cont), pHead->version,
              tstrerror(code));
     return code;
@@ -559,11 +555,11 @@ static int sdbWrite(void *param, void *data, int type) {
 
   // from wal or forward msg, oper not created, should add into hash
   if (tsSdbObj.sync != NULL) {
-    sdbDebug("record from wal forward is disposed, table:%s action:%s record:%s version:%" PRIu64 " confirm it",
+    sdbTrace("record from wal forward is disposed, table:%s action:%s record:%s version:%" PRIu64 " confirm it",
              pTable->tableName, sdbGetActionStr(action), sdbGetKeyStr(pTable, pHead->cont), pHead->version);
     syncConfirmForward(tsSdbObj.sync, pHead->version, code);
   } else {
-    sdbDebug("record from wal restore is disposed, table:%s action:%s record:%s version:%" PRIu64, pTable->tableName,
+    sdbTrace("record from wal restore is disposed, table:%s action:%s record:%s version:%" PRIu64, pTable->tableName,
              sdbGetActionStr(action), sdbGetKeyStr(pTable, pHead->cont), pHead->version);
   }
 
@@ -971,12 +967,12 @@ static void *sdbWorkerFp(void *param) {
       if (type == TAOS_QTYPE_RPC) {
         pOper = (SSdbOper *)item;
         if (pOper != NULL && pOper->cb != NULL) {
-          sdbDebug("app:%p:%p, will do callback func, index:%d", pOper->pMsg->rpcMsg.ahandle, pOper->pMsg, i);
+          sdbTrace("app:%p:%p, will do callback func, index:%d", pOper->pMsg->rpcMsg.ahandle, pOper->pMsg, i);
           pOper->retCode = (*pOper->cb)(pOper->pMsg, pOper->retCode);
         }
 
         if (pOper != NULL && pOper->pMsg != NULL) {
-          sdbDebug("app:%p:%p, msg is processed, result:%s", pOper->pMsg->rpcMsg.ahandle, pOper->pMsg,
+          sdbTrace("app:%p:%p, msg is processed, result:%s", pOper->pMsg->rpcMsg.ahandle, pOper->pMsg,
                    tstrerror(pOper->retCode));
         }
 

src/wal/src/walMain.c

@@ -30,10 +30,13 @@
 #include "tqueue.h"
 
 #define walPrefix "wal"
-#define wError(...) if (wDebugFlag & DEBUG_ERROR) {taosPrintLog("ERROR WAL ", wDebugFlag, __VA_ARGS__);}
-#define wWarn(...) if (wDebugFlag & DEBUG_WARN) {taosPrintLog("WARN WAL ", wDebugFlag, __VA_ARGS__);}
-#define wTrace(...) if (wDebugFlag & DEBUG_TRACE) {taosPrintLog("WAL ", wDebugFlag, __VA_ARGS__);}
-#define wPrint(...) {taosPrintLog("WAL ", 255, __VA_ARGS__);}
+
+#define wFatal(...) { if (wDebugFlag & DEBUG_FATAL) { taosPrintLog("WAL FATAL ", wDebugFlag, __VA_ARGS__); }}
+#define wError(...) { if (wDebugFlag & DEBUG_ERROR) { taosPrintLog("WAL ERROR ", wDebugFlag, __VA_ARGS__); }}
+#define wWarn(...)  { if (wDebugFlag & DEBUG_WARN)  { taosPrintLog("WAL WARN  ", wDebugFlag, __VA_ARGS__); }}
+#define wInfo(...)  { if (wDebugFlag & DEBUG_INFO)  { taosPrintLog("WAL INFO  ", wDebugFlag, __VA_ARGS__); }}
+#define wDebug(...) { if (wDebugFlag & DEBUG_DEBUG) { taosPrintLog("WAL DEBUG ", wDebugFlag, __VA_ARGS__); }}
+#define wTrace(...) { if (wDebugFlag & DEBUG_TRACE) { taosPrintLog("WAL TRACE ", wDebugFlag, __VA_ARGS__); }}
 
 typedef struct {
   uint64_t version;
@@ -48,8 +51,6 @@ typedef struct {
   pthread_mutex_t mutex;
 } SWal;
 
-int wDebugFlag = 135;
-
 static uint32_t walSignature = 0xFAFBFDFE;
 static int walHandleExistingFiles(const char *path);
 static int walRestoreWalFile(SWal *pWal, void *pVnode, FWalWrite writeFp);
@@ -92,7 +93,7 @@ void *walOpen(const char *path, const SWalCfg *pCfg) {
     pWal = NULL;
   } 
 
-  if (pWal) wTrace("wal:%s, it is open, level:%d", path, pWal->level);
+  if (pWal) wDebug("wal:%s, it is open, level:%d", path, pWal->level);
   return pWal;
 }
 
@@ -109,11 +110,11 @@ void walClose(void *handle) {
       if (remove(pWal->name) <0) {
         wError("wal:%s, failed to remove", pWal->name);
       } else {
-        wTrace("wal:%s, it is removed", pWal->name);
+        wDebug("wal:%s, it is removed", pWal->name);
       }
     }
   } else {
-    wTrace("wal:%s, it is closed and kept", pWal->name);
+    wDebug("wal:%s, it is closed and kept", pWal->name);
   }
 
   pthread_mutex_destroy(&pWal->mutex);
@@ -132,7 +133,7 @@ int walRenew(void *handle) {
   if (pWal->fd >=0) {
     close(pWal->fd);
     pWal->id++;
-    wTrace("wal:%s, it is closed", pWal->name);
+    wDebug("wal:%s, it is closed", pWal->name);
   }
 
   pWal->num++;
@@ -144,7 +145,7 @@ int walRenew(void *handle) {
     wError("wal:%s, failed to open(%s)", pWal->name, strerror(errno));
     terrno = TAOS_SYSTEM_ERROR(errno);
   } else {
-    wTrace("wal:%s, it is created", pWal->name);
+    wDebug("wal:%s, it is created", pWal->name);
 
     if (pWal->num > pWal->max) {
       // remove the oldest wal file
@@ -153,7 +154,7 @@ int walRenew(void *handle) {
       if (remove(name) <0) {
         wError("wal:%s, failed to remove(%s)", name, strerror(errno));
       } else {
-        wTrace("wal:%s, it is removed", name);
+        wDebug("wal:%s, it is removed", name);
       }
 
       pWal->num--;
@@ -242,7 +243,7 @@ int walRestore(void *handle, void *pVnode, int (*writeFp)(void *, void *, int))
     wError("wal:%s, messed up, count:%d max:%d min:%d", opath, count, maxId, minId);
     terrno = TSDB_CODE_WAL_APP_ERROR;
   } else {
-    wTrace("wal:%s, %d files will be restored", opath, count);
+    wDebug("wal:%s, %d files will be restored", opath, count);
 
     for (index = minId; index<=maxId; ++index) {
       snprintf(pWal->name, sizeof(pWal->name), "%s/%s%d", opath, walPrefix, index);
@@ -321,7 +322,7 @@ static int walRestoreWalFile(SWal *pWal, void *pVnode, FWalWrite writeFp) {
     return terrno;
   }
 
-  wTrace("wal:%s, start to restore", name);
+  wDebug("wal:%s, start to restore", name);
 
   while (1) {
     int ret = read(fd, pHead, sizeof(SWalHead));
@@ -395,7 +396,7 @@ int walHandleExistingFiles(const char *path) {
       }
     }
 
-    wTrace("wal:%s, %d files are moved for restoration", path, count);
+    wDebug("wal:%s, %d files are moved for restoration", path, count);
   }
   
   closedir(dir);