sysmocom
/
asterisk
11
0
Fork 0
Code Issues Pull Requests Packages Projects Releases Wiki Activity

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.

(cherry picked from commit 7e2243f9e1)
This commit is contained in:
George Joseph 2023-09-13 09:18:04 -06:00 committed by Asterisk Development Team
parent 97674e1d20
commit 9afa54b3b3
3 changed files with 44 additions and 23 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

1
build_tools/cflags-devmode.xml
View File

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

10
include/asterisk/lock.h
View File

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

56
main/lock.c
View File

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