[TD-424] audit record and db start/stop record

src/inc/tlog.h

@@ -30,6 +30,7 @@ extern "C" {
 #define DEBUG_WARN  2U
 #define DEBUG_TRACE 4U
 #define DEBUG_DUMP  8U
+#define LOG_LEN_STR  100
 
 #define AUDIT_INFO  0
 #define AUDIT_WARN  1
@@ -40,6 +41,8 @@ extern "C" {
 
 extern void (*taosLogFp)(int level, const char *const format, ...);
 
+extern void (*taosAuditFp)(int level, char * dbuser, char * result, char * content );
+
 extern void (*taosLogSqlFp)(char *sql);
 
 extern void (*taosLogAcctFp)(char *acctId, int64_t currentPointsPerSecond, int64_t maxPointsPerSecond,
@@ -63,8 +66,6 @@ void taosPrintLongString(const char *const flags, int dflag, const char *const f
 
 int taosOpenLogFileWithMaxLines(char *fn, int maxLines, int maxFileNum);
 
-void taosAuditRecord(int level, char * dbuser, char * result, char * content );
-
 void taosCloseLog();
 
 void taosResetLogFile();
@@ -82,6 +83,12 @@ void taosResetLogFile();
     (*taosLogFp)(0, __VA_ARGS__); \
   }
 
+#define taosAuditPrint(...)         \
+  if (taosAuditFp) {                \
+    (*taosAuditFp)(__VA_ARGS__); \
+  }
+
+
 // utility log function
 #define pError(...)                          \
   if (uDebugFlag & DEBUG_ERROR) {            \
@@ -203,6 +210,7 @@ extern uint32_t cdebugFlag;
 #define mLError(...) taosLogError(__VA_ARGS__) mError(__VA_ARGS__)
 #define mLWarn(...) taosLogWarn(__VA_ARGS__) mWarn(__VA_ARGS__)
 #define mLPrint(...) taosLogPrint(__VA_ARGS__) mPrint(__VA_ARGS__)
+#define aLPrint(...) taosAuditPrint(__VA_ARGS__)
 
 #ifdef __cplusplus
 }

src/modules/monitor/src/monitorSystem.c

@@ -27,7 +27,6 @@
 #include "tutil.h"
 
 #define SQL_LENGTH     1024
-#define LOG_LEN_STR    80
 #define LOG_RESULT_LEN 10
 #define IP_LEN_STR     15
 #define CHECK_INTERVAL 1000
@@ -74,6 +73,7 @@ void monitorInitDatabaseCb(void *param, TAOS_RES *result, int code);
 void monitorStartTimer();
 void monitorSaveSystemInfo();
 void monitorSaveLog(int level, const char *const format, ...);
+void taosAuditRecord(int level, char * dbuser, char * result, char * content );
 void monitorSaveAcctLog(char *acctId, int64_t currentPointsPerSecond, int64_t maxPointsPerSecond,
                         int64_t totalTimeSeries, int64_t maxTimeSeries, int64_t totalStorage, int64_t maxStorage,
                         int64_t totalQueryTime, int64_t maxQueryTime, int64_t totalInbound, int64_t maxInbound,
@@ -217,7 +217,7 @@ void monitorInitDatabase() {
   } else {
     monitor->state = MONITOR_STATE_INITIALIZED;
     monitorPrint("monitor service init success");
-
+    aLPrint(AUDIT_INFO, "system","success", "Database Started!");
     monitorStartTimer();
   }
 }
@@ -227,6 +227,7 @@ void monitorInitDatabaseCb(void *param, TAOS_RES *result, int code) {
     monitorTrace("monitor:%p, sql success, code:%d, %s", monitor->conn, code, monitor->sql);
     if (monitor->cmdIndex == MONITOR_CMD_CREATE_TB_LOG) {
       taosLogFp = monitorSaveLog;
+      taosAuditFp = taosAuditRecord;
       taosLogSqlFp = monitorExecuteSQL;
       taosLogAcctFp = monitorSaveAcctLog;
       monitorLPrint("dnode:%s is started", tsPrivateIp);
@@ -466,6 +467,9 @@ void monitorExecuteSQL(char *sql) {
 }
 
 void taosAuditRecord(int level, char * dbuser, char * result, char * content ){
+  if (monitor->state != MONITOR_STATE_INITIALIZED) {
+    return;
+  }
   char sqlcmd[1024] = {0};
   int64_t ts = taosGetTimestampUs();
 

src/rpc/src/trpc.c

@@ -935,6 +935,9 @@ int taosProcessMsgHeader(STaosHeader *pHeader, SRpcConn **ppConn, STaosRpc *pSer
             char timestr[50];
             taosTimeSecToString((time_t)authAllowTime,timestr);
             mLError("user:%s login from %s, authentication not allowed until %s", pHeader->meterId, ipstr,timestr);
+            char content[LOG_LEN_STR ] = {0};
+            snprintf(content, LOG_LEN_STR,"user:%s from %s, not allowed until %s", pHeader->meterId, ipstr,timestr);
+            aLPrint(AUDIT_ERROR, pHeader->meterId, "failure", content);             
             tTrace("%s cid:%d sid:%d id:%s, auth not allowed because failed authentication exceeds max limit, msg discarded pConn:%p, until %s", pServer->label, chann, sid,
                pConn->meterId, pConn, timestr);
             code = TSDB_CODE_AUTH_BANNED_PERIOD;
@@ -957,6 +960,9 @@ int taosProcessMsgHeader(STaosHeader *pHeader, SRpcConn **ppConn, STaosRpc *pSer
         (*pServer->ufp)(pHeader->meterId,&failedCount,&authAllowTime,true);
         
         mLError("user:%s login from %s, authentication failed", pHeader->meterId, ipstr);
+        char content[LOG_LEN_STR ] = {0};
+        snprintf(content,LOG_LEN_STR, "user:%s login from %s, authentication failed", pHeader->meterId, ipstr);
+        aLPrint(AUDIT_ERROR, pHeader->meterId, "failure", content);          
         tError("%s cid:%d sid:%d id:%s, authentication failed, msg discarded pConn:%p", pServer->label, chann, sid,
                pConn->meterId, pConn);
         code = TSDB_CODE_AUTH_FAILURE;

src/system/detail/src/dnodeService.c

@@ -36,6 +36,7 @@ void signal_handler(int signum, siginfo_t *sigInfo, void *context) {
   syslog(LOG_INFO, "Shutting down "DB_FULL_NAME" service...");
   // clean the system.
   dPrint("shut down signal is %d, sender PID:%d", signum, sigInfo->si_pid);
+  aLPrint(AUDIT_INFO,"system","success","database stopped!");
   dnodeCleanUpSystem();
   // close the syslog
   syslog(LOG_INFO, "Shut down "DB_FULL_NAME" service successfully");

src/system/detail/src/mgmtShell.c

@@ -590,9 +590,9 @@ int mgmtProcessCreateDbMsg(char *pMsg, int msgLen, SConnObj *pConn) {
     code = mgmtCreateDb(pConn->pAcct, pCreate);
     if (code == TSDB_CODE_SUCCESS) {
       mLPrint("DB:%s is created by %s", pCreate->db, pConn->pUser->user);
-      char content[1024];
-      sprintf(content, "DB:%s is created by %s", pCreate->db, pConn->pUser->user);
-      taosAuditRecord(AUDIT_INFO, pConn->pUser->user, "success", content);
+      char content[LOG_LEN_STR ] = {0};
+      snprintf(content, LOG_LEN_STR, "DB:%s is created by %s", pCreate->db, pConn->pUser->user);
+      aLPrint(AUDIT_INFO, pConn->pUser->user, "success", content);
     }
   }
 
@@ -623,9 +623,9 @@ int mgmtProcessAlterDbMsg(char *pMsg, int msgLen, SConnObj *pConn) {
     code = mgmtAlterDb(pConn->pAcct, pAlter);
     if (code == TSDB_CODE_SUCCESS) {
       mLPrint("DB:%s is altered by %s", pAlter->db, pConn->pUser->user);
-      char content[1024];
-      sprintf(content, "DB:%s is altered by %s", pAlter->db, pConn->pUser->user);
-      taosAuditRecord(AUDIT_INFO, pConn->pUser->user, "success", content);      
+      char content[LOG_LEN_STR] = {0};
+      snprintf(content, LOG_LEN_STR, "DB:%s is altered by %s", pAlter->db, pConn->pUser->user);
+      aLPrint(AUDIT_INFO, pConn->pUser->user, "success", content);      
     }
   }
 
@@ -691,9 +691,9 @@ int mgmtProcessCreateUserMsg(char *pMsg, int msgLen, SConnObj *pConn) {
     code = mgmtCreateUser(pConn->pAcct, pCreate->user, pCreate->pass);
     if (code == TSDB_CODE_SUCCESS) {
       mLPrint("user:%s is created by %s", pCreate->user, pConn->pUser->user);
-      char content[1024];
-      sprintf(content, "user:%s is created by %s", pCreate->user, pConn->pUser->user);
-      taosAuditRecord(AUDIT_INFO, pConn->pUser->user, "success", content);  
+      char content[LOG_LEN_STR] = {0};
+      snprintf(content, LOG_LEN_STR, "user:%s is created by %s", pCreate->user, pConn->pUser->user);
+      aLPrint(AUDIT_INFO, pConn->pUser->user, "success", content);  
     }
   } else {
     code = TSDB_CODE_NO_RIGHTS;
@@ -754,9 +754,9 @@ int mgmtProcessAlterUserMsg(char *pMsg, int msgLen, SConnObj *pConn) {
       taosEncryptPass((uint8_t*)pAlter->pass, strlen(pAlter->pass), pUser->pass);
       code = mgmtUpdateUser(pUser);
       mLPrint("user:%s password is altered by %s, code:%d", pAlter->user, pConn->pUser->user, code);
-      char content[1024];
-      sprintf(content, "user:%s password is altered by %s, code:%d", pAlter->user, pConn->pUser->user, code);
-      taosAuditRecord(AUDIT_INFO, pConn->pUser->user, "success", content);        
+      char content[LOG_LEN_STR] = {0};
+      snprintf(content, LOG_LEN_STR, "user:%s password is altered by %s, code:%d", pAlter->user, pConn->pUser->user, code);
+      aLPrint(AUDIT_INFO, pConn->pUser->user, "success", content);        
     } else {
       code = TSDB_CODE_NO_RIGHTS;
     }
@@ -812,6 +812,9 @@ int mgmtProcessAlterUserMsg(char *pMsg, int msgLen, SConnObj *pConn) {
       }      
       code = mgmtUpdateUser(pUser);
       mLPrint("user:%s privilege is altered by %s, code:%d", pAlter->user, pConn->pUser->user, code);
+      char content[LOG_LEN_STR] = {0};
+      snprintf(content, LOG_LEN_STR, "user:%s privilege is altered by %s, new privilege %d, code:%d", pAlter->user, pConn->pUser->user, pAlter->privilege, code);
+      aLPrint(AUDIT_INFO, pConn->pUser->user, "success", content);   
     } else {
       code = TSDB_CODE_NO_RIGHTS;
     }
@@ -875,6 +878,9 @@ int mgmtProcessDropUserMsg(char *pMsg, int msgLen, SConnObj *pConn) {
     code = mgmtDropUser(pConn->pAcct, pDrop->user);
     if (code == 0) {
       mLPrint("user:%s is dropped by %s", pDrop->user, pConn->pUser->user);
+      char content[LOG_LEN_STR] ={0};
+      snprintf(content, LOG_LEN_STR, "user:%s is dropped by %s", pDrop->user, pConn->pUser->user);
+      aLPrint(AUDIT_INFO, pConn->pUser->user, "success", content); 
     }
   } else {
     code = TSDB_CODE_NO_RIGHTS;
@@ -898,6 +904,9 @@ int mgmtProcessDropDbMsg(char *pMsg, int msgLen, SConnObj *pConn) {
     code = mgmtDropDbByName(pConn->pAcct, pDrop->db, pDrop->ignoreNotExists);
     if (code == 0) {
       mLPrint("DB:%s is dropped by %s", pDrop->db, pConn->pUser->user);
+      char content[LOG_LEN_STR] ={0};
+      snprintf(content, LOG_LEN_STR, "DB:%s is dropped by %s", pDrop->db, pConn->pUser->user);
+      aLPrint(AUDIT_INFO, pConn->pUser->user, "success", content); 
     }
   }
   taosSendSimpleRsp(pConn->thandle, TSDB_MSG_TYPE_DROP_DB_RSP, code);
@@ -1149,6 +1158,9 @@ int mgmtProcessDropTableMsg(char *pMsg, int msgLen, SConnObj *pConn) {
     if (code == 0) {
       mTrace("meter:%s is dropped by user:%s", pDrop->meterId, pConn->pUser->user);
       // mLPrint("meter:%s is dropped by user:%s", pDrop->meterId, pConn->pUser->user);
+      char content[LOG_LEN_STR] = {0};
+      snprintf(content, LOG_LEN_STR, "meter:%s is dropped by user:%s", pDrop->meterId, pConn->pUser->user);
+      aLPrint(AUDIT_INFO, pConn->pUser->user, "success", content); 
     }
 
     taosSendSimpleRsp(pConn->thandle, TSDB_MSG_TYPE_DROP_TABLE_RSP, code);
@@ -1186,6 +1198,9 @@ int mgmtProcessAlterTableMsg(char *pMsg, int msgLen, SConnObj *pConn) {
         code = mgmtAlterMeter(pDb, pAlter);
         if (code == 0) {
           mLPrint("meter:%s is altered by %s", pAlter->meterId, pConn->pUser->user);
+          char content[LOG_LEN_STR] = {0};
+          snprintf(content, LOG_LEN_STR, "meter:%s is altered by %s", pAlter->meterId, pConn->pUser->user);
+          aLPrint(AUDIT_INFO, pConn->pUser->user, "success", content);           
         }
       } else {
         code = TSDB_CODE_DB_NOT_SELECTED;
@@ -1436,6 +1451,9 @@ _rsp:
   char ipstr[24];
   tinet_ntoa(ipstr, pConn->ip);
   mLPrint("user:%s login from %s, code:%d", pConn->user, ipstr, code);
+  char content[LOG_LEN_STR] = {0};
+  snprintf(content, LOG_LEN_STR, "user:%s login from %s, code:%d", pConn->user, ipstr, code);
+  aLPrint(AUDIT_INFO,  pConn->user, "success", content);       
 
   return code;
 }

src/util/src/tlog.c

@@ -56,6 +56,7 @@ static int       taosLogFlag = 0;
 static int             openInProgress = 0;
 static pthread_mutex_t logMutex;
 void (*taosLogFp)(int level, const char *const format, ...) = NULL;
+void (*taosAuditFp)(int level, char * dbuser, char * result, char * content ) = NULL;
 void (*taosLogSqlFp)(char *sql) = NULL;
 void (*taosLogAcctFp)(char *acctId, int64_t currentPointsPerSecond, int64_t maxPointsPerSecond, int64_t totalTimeSeries,
                       int64_t maxTimeSeries, int64_t totalStorage, int64_t maxStorage, int64_t totalQueryTime,