From a7ef07a46af14800cffbebc0fc222c60b52b9e30 Mon Sep 17 00:00:00 2001 From: Benny Prijono Date: Wed, 22 Jul 2009 11:12:35 +0000 Subject: Ticket #922: Option to enable mutex related logging to assist troubleshooting concurrency problems git-svn-id: http://svn.pjsip.org/repos/pjproject/trunk@2843 74dad513-b988-da41-8d7b-12977e46ad98 --- pjlib/include/pj/config.h | 12 ++++++++++++ pjlib/include/pj/os.h | 6 +----- pjlib/src/pj/os_core_win32.c | 44 +++++++++++++++++++++++++++++--------------- 3 files changed, 42 insertions(+), 20 deletions(-) (limited to 'pjlib') diff --git a/pjlib/include/pj/config.h b/pjlib/include/pj/config.h index b51a7585..0ae89972 100644 --- a/pjlib/include/pj/config.h +++ b/pjlib/include/pj/config.h @@ -328,6 +328,18 @@ # endif #endif +/** + * Enable this macro to activate logging to mutex/semaphore related events. + * This is useful to troubleshoot concurrency problems such as deadlocks. + * In addition, you should also add PJ_LOG_HAS_THREAD_ID flag to the + * log decoration to assist the troubleshooting. + * + * Default: 0 + */ +#ifndef PJ_DEBUG_MUTEX +# define PJ_DEBUG_MUTEX 0 +#endif + /** * Expand functions in *_i.h header files as inline. * diff --git a/pjlib/include/pj/os.h b/pjlib/include/pj/os.h index 38eb8ea6..e1d3c485 100644 --- a/pjlib/include/pj/os.h +++ b/pjlib/include/pj/os.h @@ -675,11 +675,7 @@ PJ_DECL(pj_status_t) pj_mutex_destroy(pj_mutex_t *mutex); * @param mutex The mutex. * @return Non-zero if yes. */ -#if defined(PJ_DEBUG) && PJ_DEBUG != 0 - PJ_DECL(pj_bool_t) pj_mutex_is_locked(pj_mutex_t *mutex); -#else -# define pj_mutex_is_locked(mutex) 1 -#endif +PJ_DECL(pj_bool_t) pj_mutex_is_locked(pj_mutex_t *mutex); /** * @} diff --git a/pjlib/src/pj/os_core_win32.c b/pjlib/src/pj/os_core_win32.c index 47ba18a4..eac2c502 100644 --- a/pjlib/src/pj/os_core_win32.c +++ b/pjlib/src/pj/os_core_win32.c @@ -38,6 +38,17 @@ # include #endif +/* Activate mutex related logging if PJ_DEBUG_MUTEX is set, otherwise + * use default level 6 logging. + */ +#if defined(PJ_DEBUG_MUTEX) && PJ_DEBUG_MUTEX +# undef PJ_DEBUG +# define PJ_DEBUG 1 +# define LOG_MUTEX(expr) PJ_LOG(5,expr) +#else +# define LOG_MUTEX(expr) PJ_LOG(6,expr) +#endif + #define THIS_FILE "os_core_win32.c" /* @@ -904,7 +915,7 @@ PJ_DEF(pj_status_t) pj_mutex_lock(pj_mutex_t *mutex) PJ_CHECK_STACK(); PJ_ASSERT_RETURN(mutex, PJ_EINVAL); - PJ_LOG(6,(mutex->obj_name, "Mutex: thread %s is waiting", + LOG_MUTEX((mutex->obj_name, "Mutex: thread %s is waiting", pj_thread_this()->obj_name)); #if PJ_WIN32_WINNT >= 0x0400 @@ -917,7 +928,7 @@ PJ_DEF(pj_status_t) pj_mutex_lock(pj_mutex_t *mutex) status = PJ_STATUS_FROM_OS(GetLastError()); #endif - PJ_LOG(6,(mutex->obj_name, + LOG_MUTEX((mutex->obj_name, (status==PJ_SUCCESS ? "Mutex acquired by thread %s" : "FAILED by %s"), pj_thread_this()->obj_name)); @@ -948,7 +959,7 @@ PJ_DEF(pj_status_t) pj_mutex_unlock(pj_mutex_t *mutex) } #endif - PJ_LOG(6,(mutex->obj_name, "Mutex released by thread %s", + LOG_MUTEX((mutex->obj_name, "Mutex released by thread %s", pj_thread_this()->obj_name)); #if PJ_WIN32_WINNT >= 0x0400 @@ -971,7 +982,7 @@ PJ_DEF(pj_status_t) pj_mutex_trylock(pj_mutex_t *mutex) PJ_CHECK_STACK(); PJ_ASSERT_RETURN(mutex, PJ_EINVAL); - PJ_LOG(6,(mutex->obj_name, "Mutex: thread %s is trying", + LOG_MUTEX((mutex->obj_name, "Mutex: thread %s is trying", pj_thread_this()->obj_name)); #if PJ_WIN32_WINNT >= 0x0400 @@ -981,7 +992,7 @@ PJ_DEF(pj_status_t) pj_mutex_trylock(pj_mutex_t *mutex) PJ_SUCCESS : PJ_ETIMEDOUT; #endif if (status==PJ_SUCCESS) { - PJ_LOG(6,(mutex->obj_name, "Mutex acquired by thread %s", + LOG_MUTEX((mutex->obj_name, "Mutex acquired by thread %s", pj_thread_this()->obj_name)); #if PJ_DEBUG @@ -989,7 +1000,7 @@ PJ_DEF(pj_status_t) pj_mutex_trylock(pj_mutex_t *mutex) ++mutex->nesting_level; #endif } else { - PJ_LOG(6,(mutex->obj_name, "Mutex: thread %s's trylock() failed", + LOG_MUTEX((mutex->obj_name, "Mutex: thread %s's trylock() failed", pj_thread_this()->obj_name)); } @@ -1004,7 +1015,7 @@ PJ_DEF(pj_status_t) pj_mutex_destroy(pj_mutex_t *mutex) PJ_CHECK_STACK(); PJ_ASSERT_RETURN(mutex, PJ_EINVAL); - PJ_LOG(6,(mutex->obj_name, "Mutex destroyed")); + LOG_MUTEX((mutex->obj_name, "Mutex destroyed")); #if PJ_WIN32_WINNT >= 0x0400 DeleteCriticalSection(&mutex->crit); @@ -1015,15 +1026,18 @@ PJ_DEF(pj_status_t) pj_mutex_destroy(pj_mutex_t *mutex) #endif } -#if PJ_DEBUG /* * pj_mutex_is_locked() */ PJ_DEF(pj_bool_t) pj_mutex_is_locked(pj_mutex_t *mutex) { +#if PJ_DEBUG return mutex->owner == pj_thread_this(); -} +#else + pj_assert(!"PJ_DEBUG is not set!"); + return 1; #endif +} /////////////////////////////////////////////////////////////////////////////// /* @@ -1082,7 +1096,7 @@ PJ_DEF(pj_status_t) pj_sem_create( pj_pool_t *pool, sem->obj_name[PJ_MAX_OBJ_NAME-1] = '\0'; } - PJ_LOG(6, (sem->obj_name, "Semaphore created")); + LOG_MUTEX((sem->obj_name, "Semaphore created")); *sem_ptr = sem; return PJ_SUCCESS; @@ -1095,15 +1109,15 @@ static pj_status_t pj_sem_wait_for(pj_sem_t *sem, unsigned timeout) PJ_CHECK_STACK(); PJ_ASSERT_RETURN(sem, PJ_EINVAL); - PJ_LOG(6, (sem->obj_name, "Semaphore: thread %s is waiting", + LOG_MUTEX((sem->obj_name, "Semaphore: thread %s is waiting", pj_thread_this()->obj_name)); result = WaitForSingleObject(sem->hSemaphore, timeout); if (result == WAIT_OBJECT_0) { - PJ_LOG(6, (sem->obj_name, "Semaphore acquired by thread %s", + LOG_MUTEX((sem->obj_name, "Semaphore acquired by thread %s", pj_thread_this()->obj_name)); } else { - PJ_LOG(6, (sem->obj_name, "Semaphore: thread %s FAILED to acquire", + LOG_MUTEX((sem->obj_name, "Semaphore: thread %s FAILED to acquire", pj_thread_this()->obj_name)); } @@ -1145,7 +1159,7 @@ PJ_DEF(pj_status_t) pj_sem_post(pj_sem_t *sem) PJ_CHECK_STACK(); PJ_ASSERT_RETURN(sem, PJ_EINVAL); - PJ_LOG(6, (sem->obj_name, "Semaphore released by thread %s", + LOG_MUTEX((sem->obj_name, "Semaphore released by thread %s", pj_thread_this()->obj_name)); if (ReleaseSemaphore(sem->hSemaphore, 1, NULL)) @@ -1162,7 +1176,7 @@ PJ_DEF(pj_status_t) pj_sem_destroy(pj_sem_t *sem) PJ_CHECK_STACK(); PJ_ASSERT_RETURN(sem, PJ_EINVAL); - PJ_LOG(6, (sem->obj_name, "Semaphore destroyed by thread %s", + LOG_MUTEX((sem->obj_name, "Semaphore destroyed by thread %s", pj_thread_this()->obj_name)); if (CloseHandle(sem->hSemaphore)) -- cgit v1.2.3