!2 添加startup logs 替代原spshell的实体启动日志

Framework/spbase/StartUpBase.cpp

@@ -0,0 +1,201 @@
+#include "precompile.h"
+#include "StartUpBase.h"
+#include <json/json.h>
+#include <winpr/sysinfo.h>
+#include <string>
+#include <vector>
+#include <map>
+#include "log_define.h"
+#include <SpBase.h>
+
+class StartupLog {
+public:
+    struct Step {
+        std::string timestamp;
+        std::string event;
+        std::string status;
+        int from;
+        int to;
+        int result;
+
+        Step(const std::string& ts, const std::string& ev, const std::string t_status, int t_from, int t_to, int t_result)
+            : timestamp(ts), event(ev), status(t_status), from(t_from), to(t_to), result(t_result) {}
+    };
+
+    StartupLog();
+    StartupLog(const std::string& module_entity, int req_id = -1);
+    ~StartupLog();
+
+    void initialize(int req_id, const std::string& module_entity);
+    void addStep(const Step& step);
+    std::string toJSON() const;
+
+private:
+    int request_id;
+    std::string module_entity_;
+    std::vector<Step> steps_;
+};
+
+class StartupLogManager {
+public:
+
+    static StartupLogManager& getInstance();
+    //StartupLogManager::getInstance().addLog(entityName, entity_id);
+    void addLog(const std::string& module_entity, int idx); // 新增 addLog 方法
+    bool checkLogExist(int idx);
+    StartupLog& getLog(int idx);
+    /*
+    StartupLogManager::getInstance().addStep(entityName, { GetCurrentTimeStr(), "handle_req" });
+
+    */
+    void addStep(int idx, const StartupLog::Step& step);
+    void removeLog(int idx);
+
+private:
+    StartupLogManager();
+    ~StartupLogManager();
+    std::map<int, StartupLog> logs_;
+};
+
+std::string GetCurrentTimeStr();
+
+SPBASE_API int addStartupLog(const char* module_entity, int idx)
+{
+    StartupLogManager::getInstance().addLog(module_entity, idx);
+    return 0;
+}
+
+SPBASE_API int addStartupStep(int idx, const char* event, const char* status, int from, int to, int result)
+{
+    StartupLogManager::getInstance().addStep(idx, StartupLog::Step(GetCurrentTimeStr(), std::string(event), std::string(status), from, to, result));
+
+    return 0;
+}
+
+
+
+
+std::string GetCurrentTimeStr()
+{
+    char unitedNowTime[30] = "";
+    SYSTEMTIME st;
+    FILETIME utc_ft, local_ft, ft;
+
+#ifdef _WIN32
+
+    GetSystemTime(&st);
+    SystemTimeToFileTime(&st, &ft);
+    utc_ft.dwLowDateTime = (DWORD)ft.dwLowDateTime;
+    utc_ft.dwHighDateTime = (DWORD)ft.dwHighDateTime;
+    FileTimeToLocalFileTime(&utc_ft, &local_ft);
+    FileTimeToSystemTime(&local_ft, &st);
+#else
+    GetLocalTime(&st);
+#endif // _WIN32
+
+    sprintf(unitedNowTime, "%02d:%02d:%02d.%03d",
+        st.wHour, st.wMinute, st.wSecond, st.wMilliseconds);
+    return std::string(unitedNowTime);
+}
+
+
+StartupLog::StartupLog() : request_id(0) {}
+
+StartupLog::~StartupLog() {}
+
+void StartupLog::initialize(int req_id, const std::string& module_entity) {
+    request_id = req_id;
+    module_entity_ = module_entity;
+}
+
+StartupLog::StartupLog(const std::string& module_entity, int req_id)
+{
+    module_entity_ = module_entity;
+    request_id = req_id;
+}
+
+void StartupLog::addStep(const Step& step) {
+    steps_.push_back(step);
+}
+
+std::string StartupLog::toJSON() const {
+    Json::Value root;
+    root["event"] = "entity_startup";
+    root["request_id"] = request_id;
+    root["module_entity"] = module_entity_;
+
+    Json::Value steps_array(Json::arrayValue);
+    for (const auto& step : steps_) {
+        Json::Value step_obj;
+        step_obj["timestamp"] = step.timestamp;
+        step_obj["event"] = step.event;
+
+        if (!step.status.empty()) {
+            step_obj["status"] = step.status;
+        }
+        if (step.from != 0 && step.to != 0) {
+            step_obj["from"] = step.from;
+            step_obj["to"] = step.to;
+        }
+        if (step.result != 0) {
+            step_obj["result"] = step.result;
+        }
+
+        steps_array.append(step_obj);
+    }
+    root["steps"] = steps_array;
+
+    Json::FastWriter writer;
+    std::string jsonReq = writer.write(root);
+    return jsonReq;
+}
+
+StartupLogManager::StartupLogManager() {}
+
+StartupLogManager::~StartupLogManager() {}
+
+void StartupLogManager::addLog(const std::string& module_entity, int idx) {
+    if (logs_.find(idx) == logs_.end()) {
+        logs_[idx] = StartupLog(module_entity, idx); // 直接拷贝 log 对象
+    } // 如果已存在，则忽略
+}
+
+StartupLog& StartupLogManager::getLog(int idx) {
+    if (logs_.find(idx) == logs_.end()) {
+        logs_[idx] = StartupLog("", idx); // 仍然保留隐式创建的逻辑，方便使用
+    }
+    return logs_[idx];
+}
+
+bool StartupLogManager::checkLogExist(int idx)
+{
+    if (logs_.find(idx) == logs_.end())
+        return false;
+    else
+        return true;
+}
+
+void StartupLogManager::addStep(int idx, const StartupLog::Step& step) {
+    if (checkLogExist(idx))
+    {
+        StartupLog &current = getLog(idx);
+        current.addStep(step);
+        if (step.result != 0 || step.status == "startup_end")
+        {//print the logs and remove obj
+            std::string resultMsg = current.toJSON();
+            DbgWithLink(LOG_LEVEL_INFO, LOG_TYPE_SYSTEM).setAPI(__FUNCTION__)(resultMsg.c_str());
+            removeLog(idx);
+        }
+    }
+}
+
+void StartupLogManager::removeLog(int idx)
+{
+    if (logs_.find(idx) == logs_.end())
+        logs_.erase(idx);
+}
+
+StartupLogManager& StartupLogManager::getInstance() {
+    static StartupLogManager instance;
+    return instance;
+}

Framework/spbase/StartUpBase.h

@@ -0,0 +1,17 @@
+#ifndef STARTUP_LOG_H
+#define STARTUP_LOG_H
+
+
+#ifdef __cplusplus
+extern "C" {
+#endif
+
+	SPBASE_API int addStartupLog(const char* module_entity, int idx);
+	SPBASE_API int addStartupStep(int idx, const char* event, const char* status, int from, int to, int result);
+
+#ifdef __cplusplus
+} // extern "C" {
+#endif
+
+
+#endif

Framework/spbase/sp_bcm.c

@@ -17,6 +17,7 @@
 #include "dbgutil.h"
 #include <winpr/synch.h>
 #include <winpr/string.h>
+#include "StartUpBase.h"
 
 #define BCM_CMD_MSG			0x01
 #define BCM_CMD_SUBSCRIBE	0x02
@@ -339,7 +340,7 @@ static int daemon_on_pkt(sp_svc_t *svc,int epid, int svc_id, int pkt_type, int p
 			}
 			daemon_unlock(daemon);
 			if (found == 0 && (target_ent->state == EntityState_Idle || target_ent->state == EntityState_Busy)) {
-				DbgWithLinkForC(LOG_LEVEL_INFO, LOG_TYPE_SYSTEM, "notify_redirect_subscribe! target:%s", target_ent->cfg->name);
+				addStartupStep(target_ent->cfg->idx, "redirect_subscribe", "startup_end", 0, 0, 0);
 				sp_mod_mgr_notify_redirect_subscribe(sp_get_env()->mod_mgr, target_ent, &uid, svc_id, param);
 			}
 			FREE(param);

Framework/spbase/sp_mod.c

@@ -35,6 +35,7 @@
 #define TAG SPBASE_TAG("sp_mod")
 
 #include "toolkit.h"
+#include "StartUpBase.h"
 
 #define BUFSIZE 10240
 #define MOD_CMD_INIT		0
@@ -943,18 +944,20 @@ static int create_module_process(const char *mod_name, int epid, int range, int
 	CloseHandle(hUserTokenDup);
 	CloseHandle(hThisToken);
 
-	DbgWithLinkForC(LOG_LEVEL_INFO, LOG_TYPE_SYSTEM, "begin start mod by pipe, %s", mod_name);
+	addStartupStep(entity_id, "start_mod", "", 0, 0, 0);
 	//通过管道通知进程创建实体线程
 	if (NULL != (groupProcess = findGroupProcessInfo(group, mod_name)) && 0 == startModByPipe(groupProcess, writeParam)) {
 		char dstParam[10][MAX_PATH];
 		int paramNum = 0;
 		ZeroMemory(dstParam, sizeof(dstParam));
-		DbgWithLinkForC(LOG_LEVEL_INFO, LOG_TYPE_SYSTEM, "query mod by pipe, %s", mod_name);
+		addStartupStep(entity_id, "query_mod", "", 0, 0, 0);
 		if (-1 != (paramNum = queryModByPipe(groupProcess, mod_name, dstParam)))		//return paramNum
 		{
+			char processId[20];
 			HANDLE processMutex = OpenMutex(MUTEX_ALL_ACCESS, FALSE, dstParam[2]);
 			new_process->pid = (int)groupProcess->pid;
-			DbgWithLinkForC(LOG_LEVEL_INFO, LOG_TYPE_SYSTEM, "return processId %d", new_process->pid);
+			sprintf(processId, "%d", new_process->pid);
+			addStartupStep(entity_id, "open_process_id", processId, 0, 0, 0);
 			return 0;
 		}
 	}
@@ -1021,7 +1024,7 @@ static void mgr_on_entity_state(sp_mod_mgr_t *mgr, sp_entity_t *entity, int trig
 	mgr_bcast_entity_state_event(mgr, entity, SP_PKT_MOD|MOD_CMD_RECORD_STATE_EVENT, pkt);
 	iobuffer_dec_ref(pkt);
 
-	DbgWithLinkForC(LOG_LEVEL_INFO, LOG_TYPE_SYSTEM, "entity %s change state from %d to %d", entity->cfg->name, last_state, curr_state);
+	addStartupStep(entity->cfg->idx, "state_change", "", last_state, curr_state, 0);
 
 	// gui显示实体状态变化
 	env = sp_get_env();
@@ -1775,8 +1778,7 @@ static int load_module(sp_mod_mgr_t *mgr, sp_mod_t *mod, int trigger_entity_id,
 {
 	int rc = 0;
 	sp_env_t *env = sp_get_env();
-
-	DbgWithLinkForC(LOG_LEVEL_INFO, LOG_TYPE_SYSTEM, "begin load module %s", mod->cfg->name);
+	addStartupStep(mod->cfg->idx, "begin_load", "", 0, 0, 0);
 
 #ifdef _WIN32
 	sp_mod_mgr_lockEx(mod->cfg->idx);
@@ -1817,18 +1819,18 @@ static int load_module(sp_mod_mgr_t *mgr, sp_mod_t *mod, int trigger_entity_id,
 					DWORD dwRet;
 					dwRet = WaitForSingleObject(mod->process.handle, (DWORD)interval);	//wait for entity thread end
 					if (dwRet == WAIT_OBJECT_0) {
-						DbgWithLinkForC(LOG_LEVEL_ERROR, LOG_TYPE_SYSTEM, "detect %s's process exit exception!", mod->cfg->name);
+						addStartupStep(mod->cfg->idx, "mod_online", "process exit exception!", 0, 0, Error_Exception);
 						rc = Error_Exception;
 						break;
 					}
 				} else {
-					DbgWithLinkForC(LOG_LEVEL_INFO, LOG_TYPE_SYSTEM, "mod is online now!, %s", mod->cfg->name);
+					addStartupStep(mod->cfg->idx, "mod_online", "", 0, 0, 0);
 					break;
 				}
 			} 
 			else 
 			{
-				DbgWithLinkForC(LOG_LEVEL_WARN, LOG_TYPE_SYSTEM, "get epid state failed!");
+				addStartupStep(mod->cfg->idx, "mod_online", "get epid state failed!", 0, 0, Error_Exception);
 				break;
 			}
 		}
@@ -1836,9 +1838,9 @@ static int load_module(sp_mod_mgr_t *mgr, sp_mod_t *mod, int trigger_entity_id,
 		if (rc == 0)
 			rc = sp_svc_send(mgr->shell_svc, mod->cfg->idx, SP_INVALID_SVC_ID, SP_PKT_MOD|MOD_CMD_INIT, 0, NULL);
 		if (rc) {
-			DbgWithLinkForC(LOG_LEVEL_ERROR, LOG_TYPE_SYSTEM, "send out mod init cmd to %s(%d) failed: %s", mod->cfg->name, mod->cfg->idx, sp_strerror(rc));
+			addStartupStep(mod->cfg->idx, "send_init", "failed", 0, 0, rc);
 		} else {
-			DbgWithLinkForC(LOG_LEVEL_INFO, LOG_TYPE_SYSTEM, "send out mod init cmd ok!, %s", mod->cfg->name);
+			addStartupStep(mod->cfg->idx, "send_init", "", 0, 0, 0);
 			for (i = 0; i < tries; ++i) {
 #ifdef _WIN32
 				HANDLE hs[] = { mod->evt_wait_handle, mod->process.handle };	//wait for entity thread end
@@ -1853,21 +1855,22 @@ static int load_module(sp_mod_mgr_t *mgr, sp_mod_t *mod, int trigger_entity_id,
 				}
 #endif //_WIN32
 				if (dwRet == WAIT_OBJECT_0) {
-					DbgWithLinkForC(LOG_LEVEL_INFO, LOG_TYPE_SYSTEM, "receive reply from module %s ok!", mod->cfg->name);
+					addStartupStep(mod->cfg->idx, "entity_reply", "", 0, 0, 0);
 					rc = mod->wait_result;
 					if (rc != 0) {
-						DbgWithLinkForC(LOG_LEVEL_WARN, LOG_TYPE_SYSTEM, "receive reply from module %s ok! but wait rc: %s", mod->cfg->name, sp_strerror(rc));
+						addStartupStep(mod->cfg->idx, "entity_reply", "failed", 0, 0, rc);
 					}
 					break;
 				} else if (dwRet == WAIT_OBJECT_0+1) {
-					DbgWithLinkForC(LOG_LEVEL_WARN, LOG_TYPE_SYSTEM, "detect %s's process exit exception!", mod->cfg->name);
+					addStartupStep(mod->cfg->idx, "entity_reply", "process end", 0, 0, Error_Exception);
 					rc = Error_Exception;
 					break;
 				} else if(dwRet == WAIT_TIMEOUT) {
+					addStartupStep(mod->cfg->idx, "entity_reply", "timeout", 0, 0, Error_TimeOut);
 					rc = Error_TimeOut;
 				}
 				else {
-					DbgWithLinkForC(LOG_LEVEL_ERROR, LOG_TYPE_SYSTEM, "wait for multi object failed!! err=%d", GetLastError());
+					addStartupStep(mod->cfg->idx, "entity_reply", "multi obj", 0, 0, Error_Unexpect);
 					rc = Error_Unexpect;
 					break;
 				}
@@ -2084,7 +2087,7 @@ static int start_entity(sp_mod_mgr_t *mgr, sp_entity_t *ent, const char *cmdline
 	int rc = 0;
 	sp_mod_t *mod = ent->mod;
 
-	DbgWithLinkForC(LOG_LEVEL_DEBUG, LOG_TYPE_SYSTEM, "begin start entity %s", ent->cfg->name);
+	addStartupLog(mod->cfg->name, mod->cfg->idx);
 	
 #ifdef _WIN32
 	sp_mod_mgr_lockEx(mod->cfg->idx);
@@ -2101,7 +2104,7 @@ static int start_entity(sp_mod_mgr_t *mgr, sp_entity_t *ent, const char *cmdline
 			rc = sp_svc_send(mgr->shell_svc, mod->cfg->idx, ent->cfg->idx, SP_PKT_MOD|MOD_CMD_START, ent->cfg->idx, &pkt);
 			if (rc == 0) {
 				int last_state = ent->state;
-				DbgWithLinkForC(LOG_LEVEL_INFO, LOG_TYPE_SYSTEM, "start entity %s, send cmd start ok!", ent->cfg->name);
+				addStartupStep(mod->cfg->idx, "send_start", "", 0, 0, 0);
 				ent->state_start_time = y2k_time_now();
 				if (ent->first_start_time == 0)
 					ent->first_start_time = ent->state_start_time;
@@ -2109,16 +2112,16 @@ static int start_entity(sp_mod_mgr_t *mgr, sp_entity_t *ent, const char *cmdline
 				ent->state = EntityState_Starting;
 				mgr_on_entity_state(mgr, ent, trigger_entity_id, last_state, ent->state);
 			} else {
-				DbgWithLinkForC(LOG_LEVEL_INFO, LOG_TYPE_SYSTEM, "start entity %s, send cmd start failed!", ent->cfg->name);
+				addStartupStep(mod->cfg->idx, "send_start", "failed", 0, 0, Error_Unexpect);
 			}
 			if (pkt)
 				iobuffer_dec_ref(pkt);
 		} else {
 			rc = Error_InvalidState;
-			DbgWithLinkForC(LOG_LEVEL_WARN, LOG_TYPE_SYSTEM, "%s: entity %s state is not correct! current state: %d", __FUNCTION__, ent->cfg->name, (int)ent->state);
+			addStartupStep(mod->cfg->idx, "send_start", "state is not correct", 0, 0, Error_InvalidState);
 		}
 	} else {
-		DbgWithLinkForC(LOG_LEVEL_WARN, LOG_TYPE_SYSTEM, "entity's %s 's module is not load!", ent->cfg->name);
+		addStartupStep(mod->cfg->idx, "send_start", "module is not load", 0, 0, Error_InvalidState);
 		rc = Error_InvalidState;
 	}
 #ifdef _WIN32
@@ -2132,16 +2135,16 @@ static int start_entity(sp_mod_mgr_t *mgr, sp_entity_t *ent, const char *cmdline
 		HANDLE hs[] = {mod->evt_app_exit, ent->evt_wait_handle};
 		DWORD dwRet = WaitForMultipleObjects(array_size(hs), &hs[0], FALSE, PROCESS_TIMEOUT);
 		if (dwRet == WAIT_OBJECT_0) {
-			DbgWithLinkForC(LOG_LEVEL_INFO, LOG_TYPE_SYSTEM, "wait for start entity %s result, app exit!", ent->cfg->name);
+			addStartupStep(mod->cfg->idx, "wait_result", "app exit", 0, 0, Error_Unexpect);
 			rc = Error_Unexpect;
 		} else if (dwRet == WAIT_OBJECT_0+1) {
-			DbgWithLinkForC(LOG_LEVEL_INFO, LOG_TYPE_SYSTEM, "wait for start entity %s result ok, result = %d!", ent->cfg->name, ent->wait_result);
+			addStartupStep(mod->cfg->idx, "wait_result", "", 0, 0, 0);
 			rc = ent->wait_result;
 			if (rc != 0) {
-                DbgWithLinkForC(LOG_LEVEL_ERROR, LOG_TYPE_SYSTEM, "wait for starting entity %s and turned out result: %s!", ent->cfg->name, sp_strerror(ent->wait_result));
+				addStartupStep(mod->cfg->idx, "wait_result", "turned out result", 0, 0, ent->wait_result);
 			}
 		} else {
-			DbgWithLinkForC(LOG_LEVEL_WARN, LOG_TYPE_SYSTEM, "wait for start entity %s timeout!", ent->cfg->name);
+			addStartupStep(mod->cfg->idx, "wait_result", "timeout", 0, 0, Error_TimeOut);
 			rc = Error_TimeOut;
 		}
 

Framework/spshell/SpShellBase.h

@@ -0,0 +1,17 @@
+#ifndef STARTUP_LOG_H
+#define STARTUP_LOG_H
+
+
+#ifdef __cplusplus
+extern "C" {
+#endif
+
+	int addStartupLog(const char* module_entity, int idx);
+	int addStartupStep(const char* module_entity, const char* event, const char* status, int from, int to, int result);
+
+#ifdef __cplusplus
+} // extern "C" {
+#endif
+
+
+#endif

Framework/spshell/svc.cpp

@@ -26,6 +26,7 @@
 #include <winpr/sysinfo.h>
 #include <winpr/environment.h>
 #include <iniutil.h>
+#include "StartUpBase.h"
 
 static void shutdown_app(void* arg)
 {
@@ -699,8 +700,13 @@ iobuffer_t *on_entity_start(sp_rpc_server_t *server, int epid, int svc_id, int r
 	iobuffer_t *ans_pkt = NULL;
 
 	iobuffer_read(*req_pkt, IOBUF_T_I4, &entity_id, NULL);
-	DbgWithLink(LOG_LEVEL_INFO, LOG_TYPE_SYSTEM).setAPI(__FUNCTION__)("handle start entity req: %d", entity_id);
-
+	sp_entity_t* ent;
+	ent = sp_mod_mgr_find_entity_by_idx(env->mod_mgr, entity_id);
+	std::string entityName;
+	if (ent)
+		entityName = ent->mod->cfg->name;
+	addStartupLog(entityName.c_str(), entity_id);
+	addStartupStep(entity_id, "handle_req", "", 0, 0, 0);
 	iobuffer_format_read(*req_pkt, "s", &cmdline);
 	result = sp_mod_mgr_start_entity(env->mod_mgr, entity_id, cmdline, svc_id);
 	FREE(cmdline);
@@ -988,11 +994,11 @@ iobuffer_t* on_try_upload_logs_info(sp_rpc_server_t* server, int epid, int svc_i
 	iobuffer_write(ans_pkt, IOBUF_T_I4, &i_discard_full, 0);
 	iobuffer_write(ans_pkt, IOBUF_T_I4, &i_discard_RTI1002, 0);
 	iobuffer_write(ans_pkt, IOBUF_T_I4, &i_curLogNum, 0);
-	
+	/*
 	DbgWithLink(LOG_LEVEL_DEBUG, LOG_TYPE_SYSTEM)("checkUrlActive::GetSendLogInfo, TS_Suc:%d, TU_Suc:%d, BS_Suc:%d, BU_Suc:%d, beidou_Suc:%d, TS_Err:%d, TU_Err:%d, BS_Err:%d, BU_Err:%d, beidou_Err:%d, discard_forFull:%d, discard_forRTI1002:%d, curNum:%d"
 		, t_upload_TerminalSys_Suc, t_upload_TerminalUser_Suc, t_upload_BussinessSys_Suc, t_upload_BussinessUser_Suc, t_upload_beidou_Suc,
 		t_upload_TerminalSys_Err, t_upload_TerminalUser_Err, t_upload_BussinessSys_Err, t_upload_BussinessUser_Err, t_upload_beidou_Err
 		, t_discard_full, t_discard_RTI1002, curLogNum);
-
+	*/
 	return ans_pkt;
 }

Module/mod_chromium/baseEx.cpp

@@ -838,13 +838,13 @@ std::pair<std::string, std::string> SM2_Encrypt_Manager::EncryptMsg(std::string
 
 	if (!SM2SignWithSM3(m_private_key_buf, m_private_key_buf_len, (unsigned char*)msg.c_str(), msg.length(), sign, &sign_len))
 	{
-		DbgWithLink(LOG_LEVEL_INFO, LOG_TYPE_SYSTEM).setAPI(__FUNCTION__)("SM2SignWithSM3::err, can not sign msg");
+		DbgWithLink(LOG_LEVEL_INFO, LOG_TYPE_SYSTEM).setAPI(__FUNCTION__)("SM2SignWithSM3::err, can not sign msg, sign_len:%d", sign_len);
 		return std::make_pair("", "");
 	}
 
 	if(!EncWithSM2PubKey((unsigned char*)msg.c_str(), msg.length(), dstMsg, &dstMsgLen, m_opposite_public_key_buf, m_opposite_public_key_buf_len))
 	{
-		DbgWithLink(LOG_LEVEL_INFO, LOG_TYPE_SYSTEM).setAPI(__FUNCTION__)("EncWithSM2PubKey::err, can not encrypt msg");
+		DbgWithLink(LOG_LEVEL_INFO, LOG_TYPE_SYSTEM).setAPI(__FUNCTION__)("EncWithSM2PubKey::err, can not encrypt msg, m_opposite_public_key_buf_len: %d", m_opposite_public_key_buf_len);
 		return std::make_pair("", "");
 	}
 	return std::make_pair(binToHex(sign, sign_len), binToHex(dstMsg, dstMsgLen));