Z991239-351 #comment BugFix: 修复 进程退出监听钩子传参类型错误的缺陷

Common/SpBase.h

@@ -1237,11 +1237,12 @@ SPBASE_API void LogTrace(const char *pszMessage,const char *pszSourceFile,const
 SPBASE_API CSimpleStringA GetSysErrMsg(int nErrCode);
 SPBASE_API const char *_GetFileName(const char *pszFilePath);
 
-#ifdef _WIN32
+#ifdef _WIN32 //TODO: duplicate ?
 #define LOG_TRACE(pMsg, ...) \
 	LogTrace(CSimpleStringA::Format(pMsg, __VA_ARGS__), _GetFileName(__FILE__), __LINE__)
 #else
-#define LOG_TRACE(pMsg, ...)
+#define LOG_TRACE(pMsg, ...) \
+	LogTrace(CSimpleStringA::Format(pMsg, ##__VA_ARGS__), _GetFileName(__FILE__), __LINE__)
 #endif //_WIN32
 
 extern "C" SPBASE_API void Dbg(const char *str, ...);

libtoolkit/bus-unix.c

@@ -14,7 +14,7 @@
 
 #include <sys/eventfd.h>
 
-#define TAG TOOLKIT_TAG("bus_unix")
+#define TAG TOOLKIT_TAG("bus")
 
 #define BUS_RESULT_DATA		    1				// ==BUS_TYPE_PACKET, callback: callback.on_pkt,  no use
 #define BUS_RESULT_INFO	    	    2				// ==BUS_TYPE_INFO, callback: callback.on_inf
@@ -357,7 +357,7 @@ static int tcp_recv_buf(bus_endpt_t* endpt, char* buf, DWORD n)
 			return -1;
 		}
 	}
-	WLog_DBG(TAG, "fd(%d): tcp recv buf len:%d", endpt->sock_handle, n);
+	WLog_DBG(TAG, "<== fd(%d): tcp recv buf len: %d", endpt->sock_handle, n);
 	return 0;
 }
 
@@ -495,7 +495,7 @@ static int read_left_pkt(bus_endpt_t* endpt, iobuffer_t** p_pkt)
 
 	iobuffer_push_count(pkt, endpt->rx_pending_pkt_len);
 	*p_pkt = pkt;
-	WLog_DBG(TAG, "endpt(%d): reset rx_pending", endpt->epid);
+	WLog_DBG(TAG, "endpt(%d): reset rx_pending and return!", endpt->epid);
 	endpt->rx_pending = 0;
 	return 0;
 }
@@ -986,7 +986,7 @@ TOOLKIT_API int bus_endpt_send_info(bus_endpt_t* endpt, int epid, int type, iobu
 	int write_state;
 
 	assert(endpt);
-	WLog_DBG(TAG, "endpt(%d) send info: %d, %d.", endpt->epid, epid, type);
+	WLog_DBG(TAG, "==> endpt(%d) send info: %d, 0x%08X.", endpt->epid, epid, type);
 	read_state = iobuffer_get_read_state(pkt);
 	write_state = iobuffer_get_write_state(pkt);
 

libtoolkit/bus_daemon-unix.c

@@ -200,7 +200,7 @@ on_error:
 
 static void destroy_session(endpt_session_t *session)
 {
-
+	WLog_DBG(TAG, "enter {%s}", __FUNCTION__);
 	while (iobuffer_queue_count(session->tx_iobuf_queue) > 0) {
 		iobuffer_t *iobuf = iobuffer_queue_deque(session->tx_iobuf_queue);
 		endpt_session_t *ts = iobuffer_get_user_data(iobuf);
@@ -252,7 +252,8 @@ static endpt_session_t *find_session(bus_daemon_t *daemon, int epid)
 static void on_send_pkt(endpt_session_t *session, int err)
 {
 	iobuffer_t *pkt;
-
+	if(err != 0)
+		WLog_DBG(TAG, "enter {%s} err: %d", __FUNCTION__, err);
 	session_lock(session);
 	pkt = session->tx_pending_buf;	
 	session->tx_pending_buf = NULL;

libtoolkit/ioqueue-unix.c

@@ -16,7 +16,7 @@
 #include <winpr/string.h>
 #include <winpr/wlog.h>
 
-#define TAG TOOLKIT_TAG("ioqueue_unix")
+#define TAG TOOLKIT_TAG("ioqueue")
 
 #ifndef SO_UPDATE_CONNECT_CONTEXT
 #define SO_UPDATE_CONNECT_CONTEXT 0x7010

libtoolkit/process_monitor-unix.c

@@ -21,6 +21,7 @@ typedef struct cmd_entry_t
 	struct list_head entry;
 	int cmd;
 	HANDLE hproc;
+	tk_process_t* proc;
 	HANDLE wait_evt;
 	int result;
 }cmd_entry_t;

libtoolkit/process_monitor.h

@@ -21,7 +21,7 @@ typedef struct process_monitor_t process_monitor_t;
 
 // true for remove handle
 typedef int (*process_monitor_on_detect_process_end) \
-	(process_monitor_t *monitor, tk_process_t* proc, void *user_data);
+	(process_monitor_t *monitor, HANDLE hProc, void *user_data);
 
 TOOLKIT_API int process_monitor_create(process_monitor_t **p_monitor);
 TOOLKIT_API int process_monitor_destroy(process_monitor_t *monitor);

spbase/SpAsyncWait.cpp

@@ -63,6 +63,7 @@ ErrorCodeEnum SpAsyncWait::WaitAnswer(DWORD &dwUserError, DWORD dwTimeout)
 		dwTimeout = 10000;
 
 	DWORD dwRet = ::WaitForMultipleObjects(2, &hs[0], FALSE, dwTimeout);
+	Dbg("WaitAnswer return: 0x%08X", dwRet);
 	if (dwRet == WAIT_TIMEOUT) 
 	{
 		Error = Error_TimeOut;
@@ -79,6 +80,7 @@ ErrorCodeEnum SpAsyncWait::WaitAnswer(DWORD &dwUserError, DWORD dwTimeout)
 		m_curr_pkt = list_first_entry(&m_pending_pkt_list, pending_pkt, entry);
 		list_del_init(&m_curr_pkt->entry);
 		spinlock_leave(&m_lock);
+		Dbg("SpTranslateError(%d)", m_curr_pkt->dwSysError);
 		Error = SpTranslateError(m_curr_pkt->dwSysError);
 		dwUserError = m_curr_pkt->dwUserError;
 	} 
@@ -234,6 +236,7 @@ ErrorCodeEnum SpAsyncWait::AsyncGetAnswer()
 
 void SpAsyncWait::ReceiveAnsPkt(int error, int end, iobuffer_t **ans_pkt, bool bReadUserCode)
 {
+	Dbg("==> %s: error:%d, end:%d", __FUNCTION__, error, end);
 	pending_pkt *p = new pending_pkt();
 	ZeroMemory(p, sizeof(pending_pkt));
 
@@ -255,7 +258,7 @@ void SpAsyncWait::ReceiveAnsPkt(int error, int end, iobuffer_t **ans_pkt, bool b
 				iobuffer_read(p->pkt, IOBUF_T_I4, &p->dwUserError, 0);		// user error
 		}
 	}
-
+	Dbg("dwSysError: %d", p->dwSysError);
 	if (end || error) 
 	{
 		m_bEnd = TRUE;

spbase/SpBase.cpp

@@ -176,11 +176,11 @@ SPBASE_API void LogAssert(const char *pszMessage,const char *pszFile,const int n
 
 SPBASE_API void LogTrace(const char *pszMessage,const char *pszFile,const int nLine)
 {
+	sp_dbg_debug("========Trace: {%s}, file: {%s}, line: {%d}", pszMessage, _GetFileName(pszFile), nLine);
 	SpModule *pModule = GetSpModule();
 	if (pModule) {		
 		pModule->LogMessage(Log_Debug, Severity_None, 0, 0, pszMessage);
 	}
-
 	// write a copy in dbg log
 	sp_dbg_debug("Trace: {%s}, file: {%s}, line: {%d}", pszMessage, _GetFileName(pszFile), nLine);
 }

spbase/sp_iom.c

@@ -156,7 +156,7 @@ static void on_pkt(bus_endpt_t *endpt, int epid, int type, iobuffer_t **p_pkt, v
 static void on_msg(bus_endpt_t *endpt, int msg, int nparam, param_size_t params[], int *result, void *user_data)
 {
 	sp_iom_t *iom = (sp_iom_t *)user_data;
-	sp_dbg_debug("==> on msg %d, %d", msg, nparam);
+	sp_dbg_debug("==> on msg %d, %d, result? %d", msg, nparam, result != NULL ? 1: 0);
 	if (msg == IOM_T_SEND_INFO) {
 		int pkt_type = params[0];
 		int this_svc_id = params[1];
@@ -173,6 +173,7 @@ static void on_msg(bus_endpt_t *endpt, int msg, int nparam, param_size_t params[
 		iobuffer_write_head(pkt, IOBUF_T_I4, &this_svc_id, 0);
 		if (result) {
 			int state = 0;
+			sp_dbg_debug("get state first");
 			ret = bus_endpt_get_state(endpt, epid, &state);
 			if (ret == 0)
 				ret = (state == BUS_STATE_ON) ? 0 : -1;
@@ -189,7 +190,7 @@ static void on_msg(bus_endpt_t *endpt, int msg, int nparam, param_size_t params[
 			bus_endpt_send_info(endpt, epid, pkt_type, pkt);
 			iobuffer_dec_ref(pkt);
 		}
-		sp_dbg_debug("on_msg send_info end, %d, %d, %d, %d", this_svc_id, epid, svc_id, pkt_id);
+		sp_dbg_debug("on_msg send_info end, pkt type: 0x%08X, %d, %d, %d, %d", pkt_type, this_svc_id, epid, svc_id, pkt_id);
 	} else if (msg == IOM_T_GET_STATE) {
 		int epid = params[0];
 		int *state = (int*)params[1];
@@ -406,7 +407,7 @@ int sp_iom_send(sp_iom_t *iom, int this_svc_id, int epid, int svc_id, int pkt_ty
 {
 	iobuffer_t *pkt = p_pkt ? *p_pkt : NULL;
 	int rc;
-	sp_dbg_debug("== > sp_iom_send: pkt type: %d, this_svc id: %d, epid:%d, svc id:%d, pkt_id: %d",
+	sp_dbg_debug("== > sp_iom_send: pkt type: 0x%08X, this_svc id: %d, epid:%d, svc id:%d, pkt_id: %d",
 		pkt_type, this_svc_id, epid, svc_id, pkt_id);
 	if (!pkt) {
 		pkt = iobuffer_create(-1, -1);

spbase/sp_mod.c

@@ -960,13 +960,14 @@ static void mgr_on_entity_exception(sp_mod_mgr_t *mgr, sp_entity_t *entity, int
 	iobuffer_dec_ref(pkt);
 }
 
-static int on_detect_process_end(process_monitor_t *monitor, tk_process_t*  process, void *user_data)
+static int on_detect_process_end(process_monitor_t *monitor, HANDLE hproc, void *user_data)
 {
 	sp_mod_mgr_t *mgr = (sp_mod_mgr_t*)user_data;
 	sp_mod_t *mod;
-
+	//sp_dbg_debug("enter on_detect_process_end, handle: 0x%08X", hproc);
 	list_for_each_entry(mod, &mgr->mod_list, sp_mod_t, entry) {
-		if (mod->state && process_compare(&mod->process, process) == 0) {
+		//sp_dbg_debug("%s state: %d, pid: %d, handle: 0x%08X", mod->cfg->name, mod->state, mod->process.pid, mod->process.handle);
+		if (mod->state && mod->process.handle == hproc) {
 			sp_entity_t *ent;
 #ifdef _WIN32
 			sp_mod_mgr_lockEx(mod->cfg->idx);

spbase/sp_rpc.c

@@ -241,7 +241,7 @@ static void __threadpool_mgr_on_req(threadpool_t *threadpool, void *arg, int par
 static int mgr_on_pkt(sp_svc_t *svc,int epid, int svc_id, int pkt_type, int pkt_id, iobuffer_t **p_pkt, void *user_data)
 {
 	sp_rpc_client_mgr_t *mgr = (sp_rpc_client_mgr_t*)user_data;
-
+	sp_dbg_debug("sp_rpc::mgr_on_pkt: epid:%d, svc_id: %d, pkt_type:0x%08X, pkt_id: %d, rpc:%d", epid, svc_id, pkt_type, pkt_id, SP_GET_TYPE(pkt_type));
 	if (SP_GET_TYPE(pkt_type) == RPC_CMD_ANS) {
 		int rpc_id = pkt_id;
 		int slot = ((unsigned int)rpc_id) % BUCKET_SIZE;
@@ -496,6 +496,7 @@ static void client_set_error(sp_rpc_client_t *client, int error)
 		if (client->state != STATE_ERROR && client->state != STATE_TERM) {
 			if (client->state == STATE_SENT) {
 				if (client->cb.on_ans) {
+					sp_dbg_debug("%s::on_ans(%d) ", __FUNCTION__, error);
 					client->cb.on_ans(client, error, NULL, client->cb.user_data);
 				}
 			} else {
@@ -514,6 +515,7 @@ static void client_process_ans(sp_rpc_client_t *client, iobuffer_t **ans_pkt)
 		if (client->state == STATE_SENT) {
 			client->state = STATE_CALLED;
 			if (client->cb.on_ans) {
+				sp_dbg_debug("%s::on_ans() ", __FUNCTION__);
 				client->cb.on_ans(client, 0, ans_pkt, client->cb.user_data);
 			}
 		}

spbase/sp_ses.c

@@ -993,6 +993,9 @@ int sp_ses_uac_async_connect(sp_ses_uac_t *uac, int timeout, iobuffer_t **conn_p
 					uac->op_timer = NULL;
 					sp_dbg_warn("post conn, create timer failed!");
 				}
+				else {
+					sp_dbg_info("sp iom schedule timer ok! timeout %d", timeout);
+				}
 			}
 		} else {
 			iobuffer_pop_count(*conn_pkt, 24);

test/module/mod_helloclient/mod_helloclient.cpp

@@ -37,10 +37,9 @@ public:
 		HelloService_ClientBase *client = new HelloService_ClientBase(this);
 		Dbg("before connect");
 		ErrorCodeEnum Error = client->Connect();
-		Dbg("after connect");
+		Dbg("after connect: %d", Error);
 		if (Error == Error_Succeed) {
 			LOG_TRACE("connect ok!");
-
 			// invoke Ping method
 			Dbg("before ping");
 			Error = client->Ping();
@@ -60,6 +59,9 @@ public:
 
 			client->GetFunction()->CloseSession();
 		}
+		else {
+			Dbg("Connect failed!");
+		}
 		client->SafeDelete();
 #endif
 

test/module/mod_helloservice/HelloService_client_g.h

@@ -31,6 +31,7 @@ public:
 		CSmartPointer<IAsynWaitSp> spAsyncWait;
 		ErrorCodeEnum Error = Connect(spAsyncWait);
 		if (Error == Error_Succeed) {
+			Dbg("pre connect succeed, start to wait...");
 			Error = spAsyncWait->WaitAnswer();
 		}
 		return Error;

winpr/libwinpr/synch/test/CMakeLists.txt

@@ -15,7 +15,9 @@ set(${MODULE_PREFIX}_TESTS
 	TestSynchMultipleThreads.c
 	TestSynchTimerQueue.c
 	TestSynchWaitableTimer.c
-	TestSynchWaitableTimerAPC.c)
+	TestSynchWaitableTimerAPC.c
+	TestWaitSingleMultiObject.c
+	)
 
 create_test_sourcelist(${MODULE_PREFIX}_SRCS
 	${${MODULE_PREFIX}_DRIVER}

winpr/libwinpr/synch/test/TestWaitSingleMultiObject.c

@@ -0,0 +1,18 @@
+#include <winpr/crt.h>
+#include <winpr/synch.h>
+#include <winpr/sysinfo.h>
+
+int TestWaitSingleMultiObject(int argc, char* argv[])
+{
+	HANDLE sem = CreateSemaphoreA(NULL, 0, 0x7fffffff, NULL);
+	HANDLE evt = CreateEventA(NULL, TRUE, FALSE, NULL);
+	HANDLE hs[] = { sem, evt };
+	DWORD dwTimeout = 10000;
+	DWORD dwRet = WaitForMultipleObjects(2, &hs[0], FALSE, dwTimeout);
+	printf("WaitForMultipleObjects return %d\n", dwRet);
+	if (sem)
+		CloseHandle(sem);
+	if (evt)
+		CloseHandle(evt);
+	return 0;
+}

winpr/libwinpr/synch/wait.c

@@ -315,9 +315,11 @@ DWORD WaitForSingleObject(HANDLE hHandle, DWORD dwMilliseconds)
 		if (WIFEXITED(status)) {
 			//normal exit
 			process->dwExitCode = (DWORD)WEXITSTATUS(status);
+			WLog_DBG(TAG, "exit code: %d", process->dwExitCode);
 		}
 		else if (WIFSIGNALED(status)) {
 			process->dwExitCode = -WTERMSIG(status); //to comfirm
+			WLog_DBG(TAG, "exit signal: %d", process->dwExitCode);
 		}
 		else {
 			process->dwExitCode = (DWORD)process->status;
@@ -420,7 +422,7 @@ DWORD WaitForMultipleObjects(DWORD nCount, const HANDLE* lpHandles, BOOL bWaitAl
 		WLog_ERR(TAG, "invalid handles count(%" PRIu32 ")", nCount);
 		return WAIT_FAILED;
 	}
-
+	//WLog_DBG(TAG, "%s: count:%d, timeout:%d, all:%d", __FUNCTION__, nCount, dwMilliseconds, bWaitAll);
 	if (bWaitAll)
 	{
 		signalled_idx = alloca(nCount * sizeof(BOOL));
@@ -502,12 +504,12 @@ DWORD WaitForMultipleObjects(DWORD nCount, const HANDLE* lpHandles, BOOL bWaitAl
 		}
 
 #ifdef HAVE_POLL_H
-
+		//WLog_DBG(TAG, "start to poll");
 		do
 		{
 			status = poll(pollfds, polled, dwMilliseconds);
 		} while (status < 0 && errno == EINTR);
-
+		//WLog_DBG(TAG, "poll return: %d", status);
 #else
 
 		if ((dwMilliseconds != INFINITE) && (dwMilliseconds != 0))
@@ -596,9 +598,10 @@ DWORD WaitForMultipleObjects(DWORD nCount, const HANDLE* lpHandles, BOOL bWaitAl
 			{
 				DWORD rc = winpr_Handle_cleanup(lpHandles[idx]);
 
-				if (rc != WAIT_OBJECT_0)
+				if (rc != WAIT_OBJECT_0) {
+					WLog_ERR(TAG, "winpr_Handle_cleanup[%d] is not WAIT_OBJECT_0: rc %d", idx, rc);
 					return rc;
-
+				}
 				if (bWaitAll)
 				{
 					signalled_idx[idx] = TRUE;