lock.c: Separate DETECT_DEADLOCKS from DEBUG_THREADS

Previously, DETECT_DEADLOCKS depended on DEBUG_THREADS.
Unfortunately, DEBUG_THREADS adds a lot of lock tracking overhead
to all of the lock lifecycle calls whereas DETECT_DEADLOCKS just
causes the lock calls to loop over trylock in 200us intervals until
the lock is obtained and spits out log messages if it takes more
than 5 seconds.  From a code perspective, the only reason they were
tied together was for logging.  So... The ifdefs in lock.c were
refactored to allow DETECT_DEADLOCKS to be enabled without
also enabling DEBUG_THREADS.

Resolves: #321

UserNote: You no longer need to select DEBUG_THREADS to use
DETECT_DEADLOCKS.  This removes a significant amount of overhead
if you just want to detect possible deadlocks vs needing full
lock tracing.
This commit is contained in:
George Joseph 2023-09-13 09:18:04 -06:00 committed by asterisk-org-access-app[bot]
parent 95313d4727
commit 13ccbc1d08
3 changed files with 44 additions and 23 deletions

View File

@ -9,7 +9,6 @@
<support_level>extended</support_level>
</member>
<member name="DETECT_DEADLOCKS" displayname="Detect Deadlocks">
<depend>DEBUG_THREADS</depend>
<support_level>extended</support_level>
</member>
<member name="DUMP_SCHEDULER" displayname="Dump Scheduler Contents for Debugging">

View File

@ -134,14 +134,15 @@ struct ast_lock_track_flags {
*/
struct ast_mutex_info {
pthread_mutex_t mutex;
#if !defined(DEBUG_THREADS) && !defined(DEBUG_THREADS_LOOSE_ABI)
#if !defined(DEBUG_THREADS) && !defined(DEBUG_THREADS_LOOSE_ABI) && \
!defined(DETECT_DEADLOCKS)
/*!
* These fields are renamed to ensure they are never used when
* DEBUG_THREADS is not defined.
*/
struct ast_lock_track *_track;
struct ast_lock_track_flags _flags;
#elif defined(DEBUG_THREADS)
#elif defined(DEBUG_THREADS) || defined(DETECT_DEADLOCKS)
/*! Track which thread holds this mutex. */
struct ast_lock_track *track;
struct ast_lock_track_flags flags;
@ -155,14 +156,15 @@ struct ast_mutex_info {
*/
struct ast_rwlock_info {
pthread_rwlock_t lock;
#if !defined(DEBUG_THREADS) && !defined(DEBUG_THREADS_LOOSE_ABI)
#if !defined(DEBUG_THREADS) && !defined(DEBUG_THREADS_LOOSE_ABI) && \
!defined(DETECT_DEADLOCKS)
/*!
* These fields are renamed to ensure they are never used when
* DEBUG_THREADS is not defined.
*/
struct ast_lock_track *_track;
struct ast_lock_track_flags _flags;
#elif defined(DEBUG_THREADS)
#elif defined(DEBUG_THREADS) || defined(DETECT_DEADLOCKS)
/*! Track which thread holds this lock */
struct ast_lock_track *track;
struct ast_lock_track_flags flags;

View File

@ -54,7 +54,7 @@ static void __attribute__((constructor)) __mtx_init(void)
#undef pthread_cond_wait
#undef pthread_cond_timedwait
#if defined(DEBUG_THREADS)
#if defined(DEBUG_THREADS) || defined(DETECT_DEADLOCKS)
#define log_mutex_error(canlog, ...) \
do { \
if (canlog) { \
@ -148,8 +148,8 @@ int __ast_pthread_mutex_init(int tracking, const char *filename, int lineno, con
int res;
pthread_mutexattr_t attr;
#ifdef DEBUG_THREADS
#if defined(AST_MUTEX_INIT_W_CONSTRUCTORS) && defined(CAN_COMPARE_MUTEX_TO_INIT_VALUE)
#if defined(DEBUG_THREADS) && defined(AST_MUTEX_INIT_W_CONSTRUCTORS) && \
defined(CAN_COMPARE_MUTEX_TO_INIT_VALUE)
if ((t->mutex) != ((pthread_mutex_t) PTHREAD_MUTEX_INITIALIZER)) {
int canlog = tracking && strcmp(filename, "logger.c");
@ -160,6 +160,7 @@ int __ast_pthread_mutex_init(int tracking, const char *filename, int lineno, con
}
#endif /* AST_MUTEX_INIT_W_CONSTRUCTORS */
#if defined(DEBUG_THREADS) || defined(DETECT_DEADLOCKS)
t->track = NULL;
t->flags.tracking = tracking;
t->flags.setup = 0;
@ -256,9 +257,12 @@ int __ast_pthread_mutex_lock(const char *filename, int lineno, const char *func,
{
int res;
#if defined(DETECT_DEADLOCKS) || defined(DEBUG_THREADS)
int canlog = t->flags.tracking && strcmp(filename, "logger.c");
#endif
#ifdef DEBUG_THREADS
struct ast_lock_track *lt = ast_get_reentrancy(&t->track, &t->flags, 0);
int canlog = t->flags.tracking && strcmp(filename, "logger.c");
struct ast_bt *bt = NULL;
if (lt) {
@ -281,7 +285,7 @@ int __ast_pthread_mutex_lock(const char *filename, int lineno, const char *func,
}
#endif /* DEBUG_THREADS */
#if defined(DETECT_DEADLOCKS) && defined(DEBUG_THREADS)
#if defined(DETECT_DEADLOCKS)
{
time_t seconds = time(NULL);
time_t wait_time, reported_wait = 0;
@ -298,6 +302,7 @@ int __ast_pthread_mutex_lock(const char *filename, int lineno, const char *func,
if (wait_time > reported_wait && (wait_time % 5) == 0) {
log_mutex_error(canlog, "%s line %d (%s): Deadlock? waited %d sec for mutex '%s'?\n",
filename, lineno, func, (int) wait_time, mutex_name);
#ifdef DEBUG_THREADS
if (lt) {
ast_reentrancy_lock(lt);
#ifdef HAVE_BKTR
@ -311,6 +316,7 @@ int __ast_pthread_mutex_lock(const char *filename, int lineno, const char *func,
#endif
ast_reentrancy_unlock(lt);
}
#endif
reported_wait = wait_time;
if ((int) wait_time < 10) { /* Only emit an event when a deadlock starts, not every 5 seconds */
/*** DOCUMENTATION
@ -687,13 +693,14 @@ int __ast_cond_timedwait(const char *filename, int lineno, const char *func,
return res;
}
int __ast_rwlock_init(int tracking, const char *filename, int lineno, const char *func, const char *rwlock_name, ast_rwlock_t *t)
int __ast_rwlock_init(int tracking, const char *filename, int lineno, \
const char *func, const char *rwlock_name, ast_rwlock_t *t)
{
int res;
pthread_rwlockattr_t attr;
#ifdef DEBUG_THREADS
#if defined(AST_MUTEX_INIT_W_CONSTRUCTORS) && defined(CAN_COMPARE_MUTEX_TO_INIT_VALUE)
#if defined(DEBUG_THREADS) && defined(AST_MUTEX_INIT_W_CONSTRUCTORS) && \
defined(CAN_COMPARE_MUTEX_TO_INIT_VALUE)
if (t->lock != ((pthread_rwlock_t) __AST_RWLOCK_INIT_VALUE)) {
int canlog = tracking && strcmp(filename, "logger.c");
@ -704,6 +711,7 @@ int __ast_rwlock_init(int tracking, const char *filename, int lineno, const char
}
#endif /* AST_MUTEX_INIT_W_CONSTRUCTORS */
#if defined(DEBUG_THREADS) || defined(DETECT_DEADLOCKS)
t->track = NULL;
t->flags.tracking = tracking;
t->flags.setup = 0;
@ -837,13 +845,17 @@ int __ast_rwlock_unlock(const char *filename, int line, const char *func, ast_rw
return res;
}
int __ast_rwlock_rdlock(const char *filename, int line, const char *func, ast_rwlock_t *t, const char *name)
int __ast_rwlock_rdlock(const char *filename, int line, const char *func,
ast_rwlock_t *t, const char *name)
{
int res;
#if defined(DEBUG_THREADS) || defined(DETECT_DEADLOCKS)
int canlog = t->flags.tracking && strcmp(filename, "logger.c");
#endif
#ifdef DEBUG_THREADS
struct ast_lock_track *lt = ast_get_reentrancy(&t->track, &t->flags, 0);
int canlog = t->flags.tracking && strcmp(filename, "logger.c");
struct ast_bt *bt = NULL;
if (lt) {
@ -866,7 +878,7 @@ int __ast_rwlock_rdlock(const char *filename, int line, const char *func, ast_rw
}
#endif /* DEBUG_THREADS */
#if defined(DETECT_DEADLOCKS) && defined(DEBUG_THREADS)
#if defined(DETECT_DEADLOCKS)
{
time_t seconds = time(NULL);
time_t wait_time, reported_wait = 0;
@ -877,6 +889,7 @@ int __ast_rwlock_rdlock(const char *filename, int line, const char *func, ast_rw
if (wait_time > reported_wait && (wait_time % 5) == 0) {
log_mutex_error(canlog, "%s line %d (%s): Deadlock? waited %d sec for readlock '%s'?\n",
filename, line, func, (int)wait_time, name);
#ifdef DEBUG_THREADS
if (lt) {
ast_reentrancy_lock(lt);
#ifdef HAVE_BKTR
@ -890,15 +903,16 @@ int __ast_rwlock_rdlock(const char *filename, int line, const char *func, ast_rw
#endif
ast_reentrancy_unlock(lt);
}
#endif
reported_wait = wait_time;
}
usleep(200);
}
} while (res == EBUSY);
}
#else /* !DETECT_DEADLOCKS || !DEBUG_THREADS */
#else /* !DETECT_DEADLOCKS */
res = pthread_rwlock_rdlock(&t->lock);
#endif /* !DETECT_DEADLOCKS || !DEBUG_THREADS */
#endif /* !DETECT_DEADLOCKS */
#ifdef DEBUG_THREADS
if (!res && lt) {
@ -935,13 +949,17 @@ int __ast_rwlock_rdlock(const char *filename, int line, const char *func, ast_rw
return res;
}
int __ast_rwlock_wrlock(const char *filename, int line, const char *func, ast_rwlock_t *t, const char *name)
int __ast_rwlock_wrlock(const char *filename, int line, const char *func, \
ast_rwlock_t *t, const char *name)
{
int res;
#if defined(DEBUG_THREADS) || defined(DETECT_DEADLOCKS)
int canlog = t->flags.tracking && strcmp(filename, "logger.c");
#endif
#ifdef DEBUG_THREADS
struct ast_lock_track *lt = ast_get_reentrancy(&t->track, &t->flags, 0);
int canlog = t->flags.tracking && strcmp(filename, "logger.c");
struct ast_bt *bt = NULL;
if (lt) {
@ -964,7 +982,7 @@ int __ast_rwlock_wrlock(const char *filename, int line, const char *func, ast_rw
}
#endif /* DEBUG_THREADS */
#if defined(DETECT_DEADLOCKS) && defined(DEBUG_THREADS)
#ifdef DETECT_DEADLOCKS
{
time_t seconds = time(NULL);
time_t wait_time, reported_wait = 0;
@ -975,6 +993,7 @@ int __ast_rwlock_wrlock(const char *filename, int line, const char *func, ast_rw
if (wait_time > reported_wait && (wait_time % 5) == 0) {
log_mutex_error(canlog, "%s line %d (%s): Deadlock? waited %d sec for writelock '%s'?\n",
filename, line, func, (int)wait_time, name);
#ifdef DEBUG_THREADS
if (lt) {
ast_reentrancy_lock(lt);
#ifdef HAVE_BKTR
@ -988,15 +1007,16 @@ int __ast_rwlock_wrlock(const char *filename, int line, const char *func, ast_rw
#endif
ast_reentrancy_unlock(lt);
}
#endif
reported_wait = wait_time;
}
usleep(200);
}
} while (res == EBUSY);
}
#else /* !DETECT_DEADLOCKS || !DEBUG_THREADS */
#else /* !DETECT_DEADLOCKS */
res = pthread_rwlock_wrlock(&t->lock);
#endif /* !DETECT_DEADLOCKS || !DEBUG_THREADS */
#endif /* !DETECT_DEADLOCKS */
#ifdef DEBUG_THREADS
if (!res && lt) {