Merge "lock: Replace __ast_mutex_logger with private log_mutex_error."

This commit is contained in:
George Joseph
2018-10-24 07:46:11 -05:00
committed by Gerrit Code Review
3 changed files with 73 additions and 64 deletions

View File

@@ -241,8 +241,6 @@ int __ast_rwlock_trywrlock(const char *filename, int lineno, const char *func, a
#ifdef DEBUG_THREADS #ifdef DEBUG_THREADS
#define __ast_mutex_logger(...) do { if (canlog) ast_log(LOG_ERROR, __VA_ARGS__); else fprintf(stderr, __VA_ARGS__); } while (0)
#ifdef THREAD_CRASH #ifdef THREAD_CRASH
#define DO_THREAD_CRASH do { *((int *)(0)) = 1; } while(0) #define DO_THREAD_CRASH do { *((int *)(0)) = 1; } while(0)
#else #else

View File

@@ -53,6 +53,17 @@ 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)
#define log_mutex_error(canlog, ...) \
do { \
if (canlog) { \
ast_log(LOG_ERROR, __VA_ARGS__); \
} else { \
fprintf(stderr, __VA_ARGS__); \
} \
} while (0)
#endif
#if defined(DEBUG_THREADS) && defined(HAVE_BKTR) #if defined(DEBUG_THREADS) && defined(HAVE_BKTR)
static void __dump_backtrace(struct ast_bt *bt, int canlog) static void __dump_backtrace(struct ast_bt *bt, int canlog)
{ {
@@ -62,7 +73,7 @@ static void __dump_backtrace(struct ast_bt *bt, int canlog)
strings = backtrace_symbols(bt->addresses, bt->num_frames); strings = backtrace_symbols(bt->addresses, bt->num_frames);
for (i = 0; i < bt->num_frames; i++) { for (i = 0; i < bt->num_frames; i++) {
__ast_mutex_logger("%s\n", strings[i]); log_mutex_error(canlog, "%s\n", strings[i]);
} }
ast_std_free(strings); ast_std_free(strings);
@@ -141,7 +152,7 @@ int __ast_pthread_mutex_init(int tracking, const char *filename, int lineno, con
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");
__ast_mutex_logger("%s line %d (%s): NOTICE: mutex '%s' is already initialized.\n", log_mutex_error(canlog, "%s line %d (%s): NOTICE: mutex '%s' is already initialized.\n",
filename, lineno, func, mutex_name); filename, lineno, func, mutex_name);
DO_THREAD_CRASH; DO_THREAD_CRASH;
return EBUSY; return EBUSY;
@@ -178,7 +189,7 @@ int __ast_pthread_mutex_destroy(const char *filename, int lineno, const char *fu
* linked with libpthread. * linked with libpthread.
* This is not an error condition if the mutex is created on the fly. * This is not an error condition if the mutex is created on the fly.
*/ */
__ast_mutex_logger("%s line %d (%s): NOTICE: mutex '%s' is uninitialized.\n", log_mutex_error(canlog, "%s line %d (%s): NOTICE: mutex '%s' is uninitialized.\n",
filename, lineno, func, mutex_name); filename, lineno, func, mutex_name);
DO_THREAD_CRASH; DO_THREAD_CRASH;
res = EINVAL; res = EINVAL;
@@ -192,15 +203,15 @@ int __ast_pthread_mutex_destroy(const char *filename, int lineno, const char *fu
pthread_mutex_unlock(&t->mutex); pthread_mutex_unlock(&t->mutex);
break; break;
case EINVAL: case EINVAL:
__ast_mutex_logger("%s line %d (%s): Error: attempt to destroy invalid mutex '%s'.\n", log_mutex_error(canlog, "%s line %d (%s): Error: attempt to destroy invalid mutex '%s'.\n",
filename, lineno, func, mutex_name); filename, lineno, func, mutex_name);
break; break;
case EBUSY: case EBUSY:
__ast_mutex_logger("%s line %d (%s): Error: attempt to destroy locked mutex '%s'.\n", log_mutex_error(canlog, "%s line %d (%s): Error: attempt to destroy locked mutex '%s'.\n",
filename, lineno, func, mutex_name); filename, lineno, func, mutex_name);
if (lt) { if (lt) {
ast_reentrancy_lock(lt); ast_reentrancy_lock(lt);
__ast_mutex_logger("%s line %d (%s): Error: '%s' was locked here.\n", log_mutex_error(canlog, "%s line %d (%s): Error: '%s' was locked here.\n",
lt->file[ROFFSET], lt->lineno[ROFFSET], lt->func[ROFFSET], mutex_name); lt->file[ROFFSET], lt->lineno[ROFFSET], lt->func[ROFFSET], mutex_name);
#ifdef HAVE_BKTR #ifdef HAVE_BKTR
__dump_backtrace(&lt->backtrace[ROFFSET], canlog); __dump_backtrace(&lt->backtrace[ROFFSET], canlog);
@@ -215,7 +226,7 @@ int __ast_pthread_mutex_destroy(const char *filename, int lineno, const char *fu
#ifdef DEBUG_THREADS #ifdef DEBUG_THREADS
if (res) { if (res) {
__ast_mutex_logger("%s line %d (%s): Error destroying mutex %s: %s\n", log_mutex_error(canlog, "%s line %d (%s): Error destroying mutex %s: %s\n",
filename, lineno, func, mutex_name, strerror(res)); filename, lineno, func, mutex_name, strerror(res));
} }
#if defined(AST_MUTEX_INIT_W_CONSTRUCTORS) && defined(CAN_COMPARE_MUTEX_TO_INIT_VALUE) #if defined(AST_MUTEX_INIT_W_CONSTRUCTORS) && defined(CAN_COMPARE_MUTEX_TO_INIT_VALUE)
@@ -284,14 +295,14 @@ int __ast_pthread_mutex_lock(const char *filename, int lineno, const char *func,
if (res == EBUSY) { if (res == EBUSY) {
wait_time = time(NULL) - seconds; wait_time = time(NULL) - seconds;
if (wait_time > reported_wait && (wait_time % 5) == 0) { if (wait_time > reported_wait && (wait_time % 5) == 0) {
__ast_mutex_logger("%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);
if (lt) { if (lt) {
ast_reentrancy_lock(lt); ast_reentrancy_lock(lt);
#ifdef HAVE_BKTR #ifdef HAVE_BKTR
__dump_backtrace(&lt->backtrace[lt->reentrancy], canlog); __dump_backtrace(&lt->backtrace[lt->reentrancy], canlog);
#endif #endif
__ast_mutex_logger("%s line %d (%s): '%s' was locked here.\n", log_mutex_error(canlog, "%s line %d (%s): '%s' was locked here.\n",
lt->file[ROFFSET], lt->lineno[ROFFSET], lt->file[ROFFSET], lt->lineno[ROFFSET],
lt->func[ROFFSET], mutex_name); lt->func[ROFFSET], mutex_name);
#ifdef HAVE_BKTR #ifdef HAVE_BKTR
@@ -325,7 +336,7 @@ int __ast_pthread_mutex_lock(const char *filename, int lineno, const char *func,
lt->thread_id[lt->reentrancy] = pthread_self(); lt->thread_id[lt->reentrancy] = pthread_self();
lt->reentrancy++; lt->reentrancy++;
} else { } else {
__ast_mutex_logger("%s line %d (%s): '%s' really deep reentrancy!\n", log_mutex_error(canlog, "%s line %d (%s): '%s' really deep reentrancy!\n",
filename, lineno, func, mutex_name); filename, lineno, func, mutex_name);
} }
ast_reentrancy_unlock(lt); ast_reentrancy_unlock(lt);
@@ -343,7 +354,7 @@ int __ast_pthread_mutex_lock(const char *filename, int lineno, const char *func,
ast_remove_lock_info(t, bt); ast_remove_lock_info(t, bt);
} }
if (res) { if (res) {
__ast_mutex_logger("%s line %d (%s): Error obtaining mutex: %s\n", log_mutex_error(canlog, "%s line %d (%s): Error obtaining mutex: %s\n",
filename, lineno, func, strerror(res)); filename, lineno, func, strerror(res));
DO_THREAD_CRASH; DO_THREAD_CRASH;
} }
@@ -394,7 +405,7 @@ int __ast_pthread_mutex_trylock(const char *filename, int lineno, const char *fu
lt->thread_id[lt->reentrancy] = pthread_self(); lt->thread_id[lt->reentrancy] = pthread_self();
lt->reentrancy++; lt->reentrancy++;
} else { } else {
__ast_mutex_logger("%s line %d (%s): '%s' really deep reentrancy!\n", log_mutex_error(canlog, "%s line %d (%s): '%s' really deep reentrancy!\n",
filename, lineno, func, mutex_name); filename, lineno, func, mutex_name);
} }
ast_reentrancy_unlock(lt); ast_reentrancy_unlock(lt);
@@ -419,7 +430,7 @@ int __ast_pthread_mutex_unlock(const char *filename, int lineno, const char *fun
#if defined(AST_MUTEX_INIT_W_CONSTRUCTORS) && defined(CAN_COMPARE_MUTEX_TO_INIT_VALUE) #if defined(AST_MUTEX_INIT_W_CONSTRUCTORS) && 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)) {
__ast_mutex_logger("%s line %d (%s): Error: mutex '%s' is uninitialized.\n", log_mutex_error(canlog, "%s line %d (%s): Error: mutex '%s' is uninitialized.\n",
filename, lineno, func, mutex_name); filename, lineno, func, mutex_name);
DO_THREAD_CRASH; DO_THREAD_CRASH;
return EINVAL; return EINVAL;
@@ -430,9 +441,9 @@ int __ast_pthread_mutex_unlock(const char *filename, int lineno, const char *fun
if (lt) { if (lt) {
ast_reentrancy_lock(lt); ast_reentrancy_lock(lt);
if (lt->reentrancy && (lt->thread_id[ROFFSET] != pthread_self())) { if (lt->reentrancy && (lt->thread_id[ROFFSET] != pthread_self())) {
__ast_mutex_logger("%s line %d (%s): attempted unlock mutex '%s' without owning it!\n", log_mutex_error(canlog, "%s line %d (%s): attempted unlock mutex '%s' without owning it!\n",
filename, lineno, func, mutex_name); filename, lineno, func, mutex_name);
__ast_mutex_logger("%s line %d (%s): '%s' was locked here.\n", log_mutex_error(canlog, "%s line %d (%s): '%s' was locked here.\n",
lt->file[ROFFSET], lt->lineno[ROFFSET], lt->func[ROFFSET], mutex_name); lt->file[ROFFSET], lt->lineno[ROFFSET], lt->func[ROFFSET], mutex_name);
#ifdef HAVE_BKTR #ifdef HAVE_BKTR
__dump_backtrace(&lt->backtrace[ROFFSET], canlog); __dump_backtrace(&lt->backtrace[ROFFSET], canlog);
@@ -441,7 +452,7 @@ int __ast_pthread_mutex_unlock(const char *filename, int lineno, const char *fun
} }
if (--lt->reentrancy < 0) { if (--lt->reentrancy < 0) {
__ast_mutex_logger("%s line %d (%s): mutex '%s' freed more times than we've locked!\n", log_mutex_error(canlog, "%s line %d (%s): mutex '%s' freed more times than we've locked!\n",
filename, lineno, func, mutex_name); filename, lineno, func, mutex_name);
lt->reentrancy = 0; lt->reentrancy = 0;
} }
@@ -468,7 +479,7 @@ int __ast_pthread_mutex_unlock(const char *filename, int lineno, const char *fun
#ifdef DEBUG_THREADS #ifdef DEBUG_THREADS
if (res) { if (res) {
__ast_mutex_logger("%s line %d (%s): Error releasing mutex: %s\n", log_mutex_error(canlog, "%s line %d (%s): Error releasing mutex: %s\n",
filename, lineno, func, strerror(res)); filename, lineno, func, strerror(res));
DO_THREAD_CRASH; DO_THREAD_CRASH;
} }
@@ -538,7 +549,7 @@ int __ast_cond_wait(const char *filename, int lineno, const char *func,
#if defined(AST_MUTEX_INIT_W_CONSTRUCTORS) && defined(CAN_COMPARE_MUTEX_TO_INIT_VALUE) #if defined(AST_MUTEX_INIT_W_CONSTRUCTORS) && 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)) {
__ast_mutex_logger("%s line %d (%s): Error: mutex '%s' is uninitialized.\n", log_mutex_error(canlog, "%s line %d (%s): Error: mutex '%s' is uninitialized.\n",
filename, lineno, func, mutex_name); filename, lineno, func, mutex_name);
DO_THREAD_CRASH; DO_THREAD_CRASH;
return EINVAL; return EINVAL;
@@ -549,16 +560,16 @@ int __ast_cond_wait(const char *filename, int lineno, const char *func,
if (lt) { if (lt) {
ast_reentrancy_lock(lt); ast_reentrancy_lock(lt);
if (lt->reentrancy && (lt->thread_id[ROFFSET] != pthread_self())) { if (lt->reentrancy && (lt->thread_id[ROFFSET] != pthread_self())) {
__ast_mutex_logger("%s line %d (%s): attempted wait using mutex '%s' without owning it!\n", log_mutex_error(canlog, "%s line %d (%s): attempted wait using mutex '%s' without owning it!\n",
filename, lineno, func, mutex_name); filename, lineno, func, mutex_name);
__ast_mutex_logger("%s line %d (%s): '%s' was locked here.\n", log_mutex_error(canlog, "%s line %d (%s): '%s' was locked here.\n",
lt->file[ROFFSET], lt->lineno[ROFFSET], lt->func[ROFFSET], mutex_name); lt->file[ROFFSET], lt->lineno[ROFFSET], lt->func[ROFFSET], mutex_name);
#ifdef HAVE_BKTR #ifdef HAVE_BKTR
__dump_backtrace(&lt->backtrace[ROFFSET], canlog); __dump_backtrace(&lt->backtrace[ROFFSET], canlog);
#endif #endif
DO_THREAD_CRASH; DO_THREAD_CRASH;
} else if (lt->reentrancy <= 0) { } else if (lt->reentrancy <= 0) {
__ast_mutex_logger("%s line %d (%s): attempted wait using an unlocked mutex '%s'\n", log_mutex_error(canlog, "%s line %d (%s): attempted wait using an unlocked mutex '%s'\n",
filename, lineno, func, mutex_name); filename, lineno, func, mutex_name);
DO_THREAD_CRASH; DO_THREAD_CRASH;
} }
@@ -578,7 +589,7 @@ int __ast_cond_wait(const char *filename, int lineno, const char *func,
#ifdef DEBUG_THREADS #ifdef DEBUG_THREADS
if (res) { if (res) {
__ast_mutex_logger("%s line %d (%s): Error waiting on condition mutex '%s'\n", log_mutex_error(canlog, "%s line %d (%s): Error waiting on condition mutex '%s'\n",
filename, lineno, func, strerror(res)); filename, lineno, func, strerror(res));
DO_THREAD_CRASH; DO_THREAD_CRASH;
} else if (lt) { } else if (lt) {
@@ -603,7 +614,7 @@ int __ast_cond_timedwait(const char *filename, int lineno, const char *func,
#if defined(AST_MUTEX_INIT_W_CONSTRUCTORS) && defined(CAN_COMPARE_MUTEX_TO_INIT_VALUE) #if defined(AST_MUTEX_INIT_W_CONSTRUCTORS) && 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)) {
__ast_mutex_logger("%s line %d (%s): Error: mutex '%s' is uninitialized.\n", log_mutex_error(canlog, "%s line %d (%s): Error: mutex '%s' is uninitialized.\n",
filename, lineno, func, mutex_name); filename, lineno, func, mutex_name);
DO_THREAD_CRASH; DO_THREAD_CRASH;
return EINVAL; return EINVAL;
@@ -614,16 +625,16 @@ int __ast_cond_timedwait(const char *filename, int lineno, const char *func,
if (lt) { if (lt) {
ast_reentrancy_lock(lt); ast_reentrancy_lock(lt);
if (lt->reentrancy && (lt->thread_id[ROFFSET] != pthread_self())) { if (lt->reentrancy && (lt->thread_id[ROFFSET] != pthread_self())) {
__ast_mutex_logger("%s line %d (%s): attempted wait using mutex '%s' without owning it!\n", log_mutex_error(canlog, "%s line %d (%s): attempted wait using mutex '%s' without owning it!\n",
filename, lineno, func, mutex_name); filename, lineno, func, mutex_name);
__ast_mutex_logger("%s line %d (%s): '%s' was locked here.\n", log_mutex_error(canlog, "%s line %d (%s): '%s' was locked here.\n",
lt->file[ROFFSET], lt->lineno[ROFFSET], lt->func[ROFFSET], mutex_name); lt->file[ROFFSET], lt->lineno[ROFFSET], lt->func[ROFFSET], mutex_name);
#ifdef HAVE_BKTR #ifdef HAVE_BKTR
__dump_backtrace(&lt->backtrace[ROFFSET], canlog); __dump_backtrace(&lt->backtrace[ROFFSET], canlog);
#endif #endif
DO_THREAD_CRASH; DO_THREAD_CRASH;
} else if (lt->reentrancy <= 0) { } else if (lt->reentrancy <= 0) {
__ast_mutex_logger("%s line %d (%s): attempted wait using an unlocked mutex '%s'\n", log_mutex_error(canlog, "%s line %d (%s): attempted wait using an unlocked mutex '%s'\n",
filename, lineno, func, mutex_name); filename, lineno, func, mutex_name);
DO_THREAD_CRASH; DO_THREAD_CRASH;
} }
@@ -643,7 +654,7 @@ int __ast_cond_timedwait(const char *filename, int lineno, const char *func,
#ifdef DEBUG_THREADS #ifdef DEBUG_THREADS
if (res && (res != ETIMEDOUT)) { if (res && (res != ETIMEDOUT)) {
__ast_mutex_logger("%s line %d (%s): Error waiting on condition mutex '%s'\n", log_mutex_error(canlog, "%s line %d (%s): Error waiting on condition mutex '%s'\n",
filename, lineno, func, strerror(res)); filename, lineno, func, strerror(res));
DO_THREAD_CRASH; DO_THREAD_CRASH;
} else if (lt) { } else if (lt) {
@@ -665,7 +676,7 @@ int __ast_rwlock_init(int tracking, const char *filename, int lineno, const char
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");
__ast_mutex_logger("%s line %d (%s): Warning: rwlock '%s' is already initialized.\n", log_mutex_error(canlog, "%s line %d (%s): Warning: rwlock '%s' is already initialized.\n",
filename, lineno, func, rwlock_name); filename, lineno, func, rwlock_name);
DO_THREAD_CRASH; DO_THREAD_CRASH;
return EBUSY; return EBUSY;
@@ -697,7 +708,7 @@ int __ast_rwlock_destroy(const char *filename, int lineno, const char *func, con
#if defined(AST_MUTEX_INIT_W_CONSTRUCTORS) && defined(CAN_COMPARE_MUTEX_TO_INIT_VALUE) #if defined(AST_MUTEX_INIT_W_CONSTRUCTORS) && 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)) {
__ast_mutex_logger("%s line %d (%s): Warning: rwlock '%s' is uninitialized.\n", log_mutex_error(canlog, "%s line %d (%s): Warning: rwlock '%s' is uninitialized.\n",
filename, lineno, func, rwlock_name); filename, lineno, func, rwlock_name);
DO_THREAD_CRASH; DO_THREAD_CRASH;
res = EINVAL; res = EINVAL;
@@ -710,7 +721,7 @@ int __ast_rwlock_destroy(const char *filename, int lineno, const char *func, con
#ifdef DEBUG_THREADS #ifdef DEBUG_THREADS
if (res) { if (res) {
__ast_mutex_logger("%s line %d (%s): Error destroying rwlock %s: %s\n", log_mutex_error(canlog, "%s line %d (%s): Error destroying rwlock %s: %s\n",
filename, lineno, func, rwlock_name, strerror(res)); filename, lineno, func, rwlock_name, strerror(res));
} }
#if defined(AST_MUTEX_INIT_W_CONSTRUCTORS) && defined(CAN_COMPARE_MUTEX_TO_INIT_VALUE) #if defined(AST_MUTEX_INIT_W_CONSTRUCTORS) && defined(CAN_COMPARE_MUTEX_TO_INIT_VALUE)
@@ -746,7 +757,7 @@ int __ast_rwlock_unlock(const char *filename, int line, const char *func, ast_rw
#if defined(AST_MUTEX_INIT_W_CONSTRUCTORS) && defined(CAN_COMPARE_MUTEX_TO_INIT_VALUE) #if defined(AST_MUTEX_INIT_W_CONSTRUCTORS) && 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)) {
__ast_mutex_logger("%s line %d (%s): Warning: rwlock '%s' is uninitialized.\n", log_mutex_error(canlog, "%s line %d (%s): Warning: rwlock '%s' is uninitialized.\n",
filename, line, func, name); filename, line, func, name);
DO_THREAD_CRASH; DO_THREAD_CRASH;
return EINVAL; return EINVAL;
@@ -781,7 +792,7 @@ int __ast_rwlock_unlock(const char *filename, int line, const char *func, ast_rw
} }
if (lock_found && --lt->reentrancy < 0) { if (lock_found && --lt->reentrancy < 0) {
__ast_mutex_logger("%s line %d (%s): rwlock '%s' freed more times than we've locked!\n", log_mutex_error(canlog, "%s line %d (%s): rwlock '%s' freed more times than we've locked!\n",
filename, line, func, name); filename, line, func, name);
lt->reentrancy = 0; lt->reentrancy = 0;
} }
@@ -796,7 +807,7 @@ int __ast_rwlock_unlock(const char *filename, int line, const char *func, ast_rw
#ifdef DEBUG_THREADS #ifdef DEBUG_THREADS
if (res) { if (res) {
__ast_mutex_logger("%s line %d (%s): Error releasing rwlock: %s\n", log_mutex_error(canlog, "%s line %d (%s): Error releasing rwlock: %s\n",
filename, line, func, strerror(res)); filename, line, func, strerror(res));
DO_THREAD_CRASH; DO_THREAD_CRASH;
} }
@@ -843,14 +854,14 @@ int __ast_rwlock_rdlock(const char *filename, int line, const char *func, ast_rw
if (res == EBUSY) { if (res == EBUSY) {
wait_time = time(NULL) - seconds; wait_time = time(NULL) - seconds;
if (wait_time > reported_wait && (wait_time % 5) == 0) { if (wait_time > reported_wait && (wait_time % 5) == 0) {
__ast_mutex_logger("%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);
if (lt) { if (lt) {
ast_reentrancy_lock(lt); ast_reentrancy_lock(lt);
#ifdef HAVE_BKTR #ifdef HAVE_BKTR
__dump_backtrace(&lt->backtrace[lt->reentrancy], canlog); __dump_backtrace(&lt->backtrace[lt->reentrancy], canlog);
#endif #endif
__ast_mutex_logger("%s line %d (%s): '%s' was locked here.\n", log_mutex_error(canlog, "%s line %d (%s): '%s' was locked here.\n",
lt->file[lt->reentrancy-1], lt->lineno[lt->reentrancy-1], lt->file[lt->reentrancy-1], lt->lineno[lt->reentrancy-1],
lt->func[lt->reentrancy-1], name); lt->func[lt->reentrancy-1], name);
#ifdef HAVE_BKTR #ifdef HAVE_BKTR
@@ -894,7 +905,7 @@ int __ast_rwlock_rdlock(const char *filename, int line, const char *func, ast_rw
} }
if (res) { if (res) {
__ast_mutex_logger("%s line %d (%s): Error obtaining read lock: %s\n", log_mutex_error(canlog, "%s line %d (%s): Error obtaining read lock: %s\n",
filename, line, func, strerror(res)); filename, line, func, strerror(res));
DO_THREAD_CRASH; DO_THREAD_CRASH;
} }
@@ -941,14 +952,14 @@ int __ast_rwlock_wrlock(const char *filename, int line, const char *func, ast_rw
if (res == EBUSY) { if (res == EBUSY) {
wait_time = time(NULL) - seconds; wait_time = time(NULL) - seconds;
if (wait_time > reported_wait && (wait_time % 5) == 0) { if (wait_time > reported_wait && (wait_time % 5) == 0) {
__ast_mutex_logger("%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);
if (lt) { if (lt) {
ast_reentrancy_lock(lt); ast_reentrancy_lock(lt);
#ifdef HAVE_BKTR #ifdef HAVE_BKTR
__dump_backtrace(&lt->backtrace[lt->reentrancy], canlog); __dump_backtrace(&lt->backtrace[lt->reentrancy], canlog);
#endif #endif
__ast_mutex_logger("%s line %d (%s): '%s' was locked here.\n", log_mutex_error(canlog, "%s line %d (%s): '%s' was locked here.\n",
lt->file[lt->reentrancy-1], lt->lineno[lt->reentrancy-1], lt->file[lt->reentrancy-1], lt->lineno[lt->reentrancy-1],
lt->func[lt->reentrancy-1], name); lt->func[lt->reentrancy-1], name);
#ifdef HAVE_BKTR #ifdef HAVE_BKTR
@@ -991,7 +1002,7 @@ int __ast_rwlock_wrlock(const char *filename, int line, const char *func, ast_rw
ast_remove_lock_info(t, bt); ast_remove_lock_info(t, bt);
} }
if (res) { if (res) {
__ast_mutex_logger("%s line %d (%s): Error obtaining write lock: %s\n", log_mutex_error(canlog, "%s line %d (%s): Error obtaining write lock: %s\n",
filename, line, func, strerror(res)); filename, line, func, strerror(res));
DO_THREAD_CRASH; DO_THREAD_CRASH;
} }
@@ -1073,7 +1084,7 @@ int __ast_rwlock_timedrdlock(const char *filename, int line, const char *func, a
ast_remove_lock_info(t, bt); ast_remove_lock_info(t, bt);
} }
if (res) { if (res) {
__ast_mutex_logger("%s line %d (%s): Error obtaining read lock: %s\n", log_mutex_error(canlog, "%s line %d (%s): Error obtaining read lock: %s\n",
filename, line, func, strerror(res)); filename, line, func, strerror(res));
DO_THREAD_CRASH; DO_THREAD_CRASH;
} }
@@ -1155,7 +1166,7 @@ int __ast_rwlock_timedwrlock(const char *filename, int line, const char *func, a
ast_remove_lock_info(t, bt); ast_remove_lock_info(t, bt);
} }
if (res) { if (res) {
__ast_mutex_logger("%s line %d (%s): Error obtaining read lock: %s\n", log_mutex_error(canlog, "%s line %d (%s): Error obtaining read lock: %s\n",
filename, line, func, strerror(res)); filename, line, func, strerror(res));
DO_THREAD_CRASH; DO_THREAD_CRASH;
} }

View File

@@ -196,7 +196,7 @@ int mtx_prof = -1;
#ifdef DEBUG_THREADS #ifdef DEBUG_THREADS
#define __ast_mutex_logger(...) do { if (canlog) ast_log(LOG_ERROR, __VA_ARGS__); else fprintf(stderr, __VA_ARGS__); } while (0) #define log_mutex_error(canlog, ...) do { if (canlog) ast_log(LOG_ERROR, __VA_ARGS__); else fprintf(stderr, __VA_ARGS__); } while (0)
#ifdef THREAD_CRASH #ifdef THREAD_CRASH
#define DO_THREAD_CRASH do { *((int *)(0)) = 1; } while(0) #define DO_THREAD_CRASH do { *((int *)(0)) = 1; } while(0)
@@ -239,9 +239,9 @@ static inline int __ast_pthread_mutex_init_attr(const char *filename, int lineno
if ((t->mutex) != ((pthread_mutex_t) PTHREAD_MUTEX_INITIALIZER)) { if ((t->mutex) != ((pthread_mutex_t) PTHREAD_MUTEX_INITIALIZER)) {
if ((t->mutex) != (empty_mutex)) { if ((t->mutex) != (empty_mutex)) {
__ast_mutex_logger("%s line %d (%s): Error: mutex '%s' is already initialized.\n", log_mutex_error(canlog, "%s line %d (%s): Error: mutex '%s' is already initialized.\n",
filename, lineno, func, mutex_name); filename, lineno, func, mutex_name);
__ast_mutex_logger("%s line %d (%s): Error: previously initialization of mutex '%s'.\n", log_mutex_error(canlog, "%s line %d (%s): Error: previously initialization of mutex '%s'.\n",
t->file[0], t->lineno[0], t->func[0], mutex_name); t->file[0], t->lineno[0], t->func[0], mutex_name);
DO_THREAD_CRASH; DO_THREAD_CRASH;
return 0; return 0;
@@ -278,7 +278,7 @@ static inline int __ast_pthread_mutex_destroy(const char *filename, int lineno,
#ifdef AST_MUTEX_INIT_W_CONSTRUCTORS #ifdef AST_MUTEX_INIT_W_CONSTRUCTORS
if ((t->mutex) == ((pthread_mutex_t) PTHREAD_MUTEX_INITIALIZER)) { if ((t->mutex) == ((pthread_mutex_t) PTHREAD_MUTEX_INITIALIZER)) {
__ast_mutex_logger("%s line %d (%s): Error: mutex '%s' is uninitialized.\n", log_mutex_error(canlog, "%s line %d (%s): Error: mutex '%s' is uninitialized.\n",
filename, lineno, func, mutex_name); filename, lineno, func, mutex_name);
} }
#endif #endif
@@ -289,19 +289,19 @@ static inline int __ast_pthread_mutex_destroy(const char *filename, int lineno,
pthread_mutex_unlock(&t->mutex); pthread_mutex_unlock(&t->mutex);
break; break;
case EINVAL: case EINVAL:
__ast_mutex_logger("%s line %d (%s): Error: attempt to destroy invalid mutex '%s'.\n", log_mutex_error(canlog, "%s line %d (%s): Error: attempt to destroy invalid mutex '%s'.\n",
filename, lineno, func, mutex_name); filename, lineno, func, mutex_name);
break; break;
case EBUSY: case EBUSY:
__ast_mutex_logger("%s line %d (%s): Error: attempt to destroy locked mutex '%s'.\n", log_mutex_error(canlog, "%s line %d (%s): Error: attempt to destroy locked mutex '%s'.\n",
filename, lineno, func, mutex_name); filename, lineno, func, mutex_name);
__ast_mutex_logger("%s line %d (%s): Error: '%s' was locked here.\n", log_mutex_error(canlog, "%s line %d (%s): Error: '%s' was locked here.\n",
t->file[t->reentrancy-1], t->lineno[t->reentrancy-1], t->func[t->reentrancy-1], mutex_name); t->file[t->reentrancy-1], t->lineno[t->reentrancy-1], t->func[t->reentrancy-1], mutex_name);
break; break;
} }
if ((res = pthread_mutex_destroy(&t->mutex))) if ((res = pthread_mutex_destroy(&t->mutex)))
__ast_mutex_logger("%s line %d (%s): Error destroying mutex: %s\n", log_mutex_error(canlog, "%s line %d (%s): Error destroying mutex: %s\n",
filename, lineno, func, strerror(res)); filename, lineno, func, strerror(res));
#ifndef PTHREAD_RECURSIVE_MUTEX_INITIALIZER_NP #ifndef PTHREAD_RECURSIVE_MUTEX_INITIALIZER_NP
else else
@@ -322,7 +322,7 @@ static inline int __ast_pthread_mutex_lock(const char *filename, int lineno, con
#if defined(AST_MUTEX_INIT_W_CONSTRUCTORS) #if defined(AST_MUTEX_INIT_W_CONSTRUCTORS)
if ((t->mutex) == ((pthread_mutex_t) PTHREAD_MUTEX_INITIALIZER)) { if ((t->mutex) == ((pthread_mutex_t) PTHREAD_MUTEX_INITIALIZER)) {
__ast_mutex_logger("%s line %d (%s): Error: mutex '%s' is uninitialized.\n", log_mutex_error(canlog, "%s line %d (%s): Error: mutex '%s' is uninitialized.\n",
filename, lineno, func, mutex_name); filename, lineno, func, mutex_name);
ast_mutex_init(t); ast_mutex_init(t);
} }
@@ -343,9 +343,9 @@ static inline int __ast_pthread_mutex_lock(const char *filename, int lineno, con
if (res == EBUSY) { if (res == EBUSY) {
current = time(NULL); current = time(NULL);
if ((current - seconds) && (!((current - seconds) % 5))) { if ((current - seconds) && (!((current - seconds) % 5))) {
__ast_mutex_logger("%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)(current - seconds), mutex_name); filename, lineno, func, (int)(current - seconds), mutex_name);
__ast_mutex_logger("%s line %d (%s): '%s' was locked here.\n", log_mutex_error(canlog, "%s line %d (%s): '%s' was locked here.\n",
t->file[t->reentrancy-1], t->lineno[t->reentrancy-1], t->file[t->reentrancy-1], t->lineno[t->reentrancy-1],
t->func[t->reentrancy-1], mutex_name); t->func[t->reentrancy-1], mutex_name);
} }
@@ -371,11 +371,11 @@ static inline int __ast_pthread_mutex_lock(const char *filename, int lineno, con
t->thread[t->reentrancy] = pthread_self(); t->thread[t->reentrancy] = pthread_self();
t->reentrancy++; t->reentrancy++;
} else { } else {
__ast_mutex_logger("%s line %d (%s): '%s' really deep reentrancy!\n", log_mutex_error(canlog, "%s line %d (%s): '%s' really deep reentrancy!\n",
filename, lineno, func, mutex_name); filename, lineno, func, mutex_name);
} }
} else { } else {
__ast_mutex_logger("%s line %d (%s): Error obtaining mutex: %s\n", log_mutex_error(canlog, "%s line %d (%s): Error obtaining mutex: %s\n",
filename, lineno, func, strerror(errno)); filename, lineno, func, strerror(errno));
DO_THREAD_CRASH; DO_THREAD_CRASH;
} }
@@ -391,7 +391,7 @@ static inline int __ast_pthread_mutex_trylock(const char *filename, int lineno,
#if defined(AST_MUTEX_INIT_W_CONSTRUCTORS) #if defined(AST_MUTEX_INIT_W_CONSTRUCTORS)
if ((t->mutex) == ((pthread_mutex_t) PTHREAD_MUTEX_INITIALIZER)) { if ((t->mutex) == ((pthread_mutex_t) PTHREAD_MUTEX_INITIALIZER)) {
__ast_mutex_logger("%s line %d (%s): Error: mutex '%s' is uninitialized.\n", log_mutex_error(canlog, "%s line %d (%s): Error: mutex '%s' is uninitialized.\n",
filename, lineno, func, mutex_name); filename, lineno, func, mutex_name);
ast_mutex_init(t); ast_mutex_init(t);
} }
@@ -405,11 +405,11 @@ static inline int __ast_pthread_mutex_trylock(const char *filename, int lineno,
t->thread[t->reentrancy] = pthread_self(); t->thread[t->reentrancy] = pthread_self();
t->reentrancy++; t->reentrancy++;
} else { } else {
__ast_mutex_logger("%s line %d (%s): '%s' really deep reentrancy!\n", log_mutex_error(canlog, "%s line %d (%s): '%s' really deep reentrancy!\n",
filename, lineno, func, mutex_name); filename, lineno, func, mutex_name);
} }
} else { } else {
__ast_mutex_logger("%s line %d (%s): Warning: '%s' was locked here.\n", log_mutex_error(canlog, "%s line %d (%s): Warning: '%s' was locked here.\n",
t->file[t->reentrancy-1], t->lineno[t->reentrancy-1], t->func[t->reentrancy-1], mutex_name); t->file[t->reentrancy-1], t->lineno[t->reentrancy-1], t->func[t->reentrancy-1], mutex_name);
} }
@@ -424,21 +424,21 @@ static inline int __ast_pthread_mutex_unlock(const char *filename, int lineno, c
#ifdef AST_MUTEX_INIT_W_CONSTRUCTORS #ifdef AST_MUTEX_INIT_W_CONSTRUCTORS
if ((t->mutex) == ((pthread_mutex_t) PTHREAD_MUTEX_INITIALIZER)) { if ((t->mutex) == ((pthread_mutex_t) PTHREAD_MUTEX_INITIALIZER)) {
__ast_mutex_logger("%s line %d (%s): Error: mutex '%s' is uninitialized.\n", log_mutex_error(canlog, "%s line %d (%s): Error: mutex '%s' is uninitialized.\n",
filename, lineno, func, mutex_name); filename, lineno, func, mutex_name);
} }
#endif #endif
if (t->reentrancy && (t->thread[t->reentrancy-1] != pthread_self())) { if (t->reentrancy && (t->thread[t->reentrancy-1] != pthread_self())) {
__ast_mutex_logger("%s line %d (%s): attempted unlock mutex '%s' without owning it!\n", log_mutex_error(canlog, "%s line %d (%s): attempted unlock mutex '%s' without owning it!\n",
filename, lineno, func, mutex_name); filename, lineno, func, mutex_name);
__ast_mutex_logger("%s line %d (%s): '%s' was locked here.\n", log_mutex_error(canlog, "%s line %d (%s): '%s' was locked here.\n",
t->file[t->reentrancy-1], t->lineno[t->reentrancy-1], t->func[t->reentrancy-1], mutex_name); t->file[t->reentrancy-1], t->lineno[t->reentrancy-1], t->func[t->reentrancy-1], mutex_name);
DO_THREAD_CRASH; DO_THREAD_CRASH;
} }
if (--t->reentrancy < 0) { if (--t->reentrancy < 0) {
__ast_mutex_logger("%s line %d (%s): mutex '%s' freed more times than we've locked!\n", log_mutex_error(canlog, "%s line %d (%s): mutex '%s' freed more times than we've locked!\n",
filename, lineno, func, mutex_name); filename, lineno, func, mutex_name);
t->reentrancy = 0; t->reentrancy = 0;
} }
@@ -451,7 +451,7 @@ static inline int __ast_pthread_mutex_unlock(const char *filename, int lineno, c
} }
if ((res = pthread_mutex_unlock(&t->mutex))) { if ((res = pthread_mutex_unlock(&t->mutex))) {
__ast_mutex_logger("%s line %d (%s): Error releasing mutex: %s\n", log_mutex_error(canlog, "%s line %d (%s): Error releasing mutex: %s\n",
filename, lineno, func, strerror(res)); filename, lineno, func, strerror(res));
DO_THREAD_CRASH; DO_THREAD_CRASH;
} }