Fix some issues with rwlock corruption that caused deadlock like symptoms.

When dvossel and I were doing some load testing last week, we noticed that we
could make Asterisk trunk lock up instantly when we started generating a bunch
of calls.  The backtraces of locked threads were bizarre, and many were stuck
on an _unlock_ of an rwlock.

The changes are:

1) Fix a number of places where a backtrace would be loaded into an invalid
   index of the backtrace array.  It's an off by one error, which ends up
   writing over the rwlock itself.

2) Ensure that in the array of held locks, we NULL out an index once it is
   not being used so that it's not confusing when analyzing its contents.

3) Remove a bunch of logging referring to an rwlock operating being done
   with "deep reentrancy".  It is normal for _many_ threads to hold a
   read lock on an rwlock.


git-svn-id: https://origsvn.digium.com/svn/asterisk/trunk@184531 65c4cc65-6c06-0410-ace0-fbb531ad65f3

1 files changed, 39 insertions, 49 deletions

diff --git a/include/asterisk/lock.h b/include/asterisk/lock.h
index 1b2e1813f..643bf1c60 100644
--- a/include/asterisk/lock.h
+++ b/include/asterisk/lock.h
@@ -500,8 +500,10 @@ static inline int __ast_pthread_mutex_lock(const char *filename, int lineno, con
 	if (t->tracking) {
 #ifdef HAVE_BKTR
 		ast_reentrancy_lock(lt);
-		ast_bt_get_addresses(&lt->backtrace[lt->reentrancy]);
-		bt = &lt->backtrace[lt->reentrancy];
+		if (lt->reentrancy != AST_MAX_REENTRANCY) {
+			ast_bt_get_addresses(&lt->backtrace[lt->reentrancy]);
+			bt = &lt->backtrace[lt->reentrancy];
+		}
 		ast_reentrancy_unlock(lt);
 		ast_store_lock_info(AST_MUTEX, filename, lineno, func, mutex_name, t, bt);
 #else
@@ -622,8 +624,10 @@ static inline int __ast_pthread_mutex_trylock(const char *filename, int lineno,
 	if (t->tracking) {
 #ifdef HAVE_BKTR
 		ast_reentrancy_lock(lt);
-		ast_bt_get_addresses(&lt->backtrace[lt->reentrancy]);
-		bt = &lt->backtrace[lt->reentrancy];
+		if (lt->reentrancy != AST_MAX_REENTRANCY) {
+			ast_bt_get_addresses(&lt->backtrace[lt->reentrancy]);
+			bt = &lt->backtrace[lt->reentrancy];
+		}
 		ast_reentrancy_unlock(lt);
 		ast_store_lock_info(AST_MUTEX, filename, lineno, func, mutex_name, t, bt);
 #else
@@ -1069,6 +1073,7 @@ static inline int _ast_rwlock_unlock(ast_rwlock_t *t, const char *name,
 #ifdef HAVE_BKTR
 	struct ast_bt *bt = NULL;
 #endif
+	int lock_found = 0;
 
 
 #ifdef AST_MUTEX_INIT_W_CONSTRUCTORS
@@ -1086,44 +1091,35 @@ static inline int _ast_rwlock_unlock(ast_rwlock_t *t, const char *name,
 
 	ast_reentrancy_lock(lt);
 	if (lt->reentrancy) {
-		int lock_found = 0;
 		int i;
 		pthread_t self = pthread_self();
-		for (i = lt->reentrancy-1; i >= 0; --i) {
+		for (i = lt->reentrancy - 1; i >= 0; --i) {
 			if (lt->thread[i] == self) {
 				lock_found = 1;
-				if (i != lt->reentrancy-1) {
-					lt->file[i] = lt->file[lt->reentrancy-1];
-					lt->lineno[i] = lt->lineno[lt->reentrancy-1];
-					lt->func[i] = lt->func[lt->reentrancy-1];
-					lt->thread[i] = lt->thread[lt->reentrancy-1];
+				if (i != lt->reentrancy - 1) {
+					lt->file[i] = lt->file[lt->reentrancy - 1];
+					lt->lineno[i] = lt->lineno[lt->reentrancy - 1];
+					lt->func[i] = lt->func[lt->reentrancy - 1];
+					lt->thread[i] = lt->thread[lt->reentrancy - 1];
 				}
-				break;
-			}
-		}
-		if (!lock_found) {
-			__ast_mutex_logger("%s line %d (%s): attempted unlock rwlock '%s' without owning it!\n",
-						filename, line, func, name);
-			__ast_mutex_logger("%s line %d (%s): '%s' was last locked here.\n",
-					lt->file[lt->reentrancy-1], lt->lineno[lt->reentrancy-1], lt->func[lt->reentrancy-1], name);
 #ifdef HAVE_BKTR
-			__dump_backtrace(&lt->backtrace[lt->reentrancy-1], canlog);
+				bt = &lt->backtrace[i];
 #endif
-			DO_THREAD_CRASH;
+				lt->file[lt->reentrancy - 1] = NULL;
+				lt->lineno[lt->reentrancy - 1] = 0;
+				lt->func[lt->reentrancy - 1] = NULL;
+				lt->thread[lt->reentrancy - 1] = AST_PTHREADT_NULL;
+				break;
+			}
 		}
 	}
 
-	if (--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",
 				filename, line, func, name);
 		lt->reentrancy = 0;
 	}
 
-#ifdef HAVE_BKTR
-	if (lt->reentrancy) {
-		bt = &lt->backtrace[lt->reentrancy - 1];
-	}
-#endif
 	ast_reentrancy_unlock(lt);
 
 	if (t->tracking) {
@@ -1171,8 +1167,10 @@ static inline int _ast_rwlock_rdlock(ast_rwlock_t *t, const char *name,
 	if (t->tracking) {
 #ifdef HAVE_BKTR
 		ast_reentrancy_lock(lt);
-		ast_bt_get_addresses(&lt->backtrace[lt->reentrancy]);
-		bt = &lt->backtrace[lt->reentrancy];
+		if (lt->reentrancy != AST_MAX_REENTRANCY) {
+			ast_bt_get_addresses(&lt->backtrace[lt->reentrancy]);
+			bt = &lt->backtrace[lt->reentrancy];
+		}
 		ast_reentrancy_unlock(lt);
 		ast_store_lock_info(AST_RDLOCK, filename, line, func, name, t, bt);
 #else
@@ -1220,9 +1218,6 @@ static inline int _ast_rwlock_rdlock(ast_rwlock_t *t, const char *name,
 			lt->func[lt->reentrancy] = func;
 			lt->thread[lt->reentrancy] = pthread_self();
 			lt->reentrancy++;
-		} else {
-			__ast_mutex_logger("%s line %d (%s): read lock '%s' really deep reentrancy!\n",
-					filename, line, func, name);
 		}
 		ast_reentrancy_unlock(lt);
 		if (t->tracking) {
@@ -1280,8 +1275,10 @@ static inline int _ast_rwlock_wrlock(ast_rwlock_t *t, const char *name,
 	if (t->tracking) {
 #ifdef HAVE_BKTR
 		ast_reentrancy_lock(lt);
-		ast_bt_get_addresses(&lt->backtrace[lt->reentrancy]);
-		bt = &lt->backtrace[lt->reentrancy];
+		if (lt->reentrancy != AST_MAX_REENTRANCY) {
+			ast_bt_get_addresses(&lt->backtrace[lt->reentrancy]);
+			bt = &lt->backtrace[lt->reentrancy];
+		}
 		ast_reentrancy_unlock(lt);
 		ast_store_lock_info(AST_WRLOCK, filename, line, func, name, t, bt);
 #else
@@ -1328,9 +1325,6 @@ static inline int _ast_rwlock_wrlock(ast_rwlock_t *t, const char *name,
 			lt->func[lt->reentrancy] = func;
 			lt->thread[lt->reentrancy] = pthread_self();
 			lt->reentrancy++;
-		} else {
-			__ast_mutex_logger("%s line %d (%s): write lock '%s' really deep reentrancy!\n",
-					filename, line, func, name);
 		}
 		ast_reentrancy_unlock(lt);
 		if (t->tracking) {
@@ -1364,7 +1358,6 @@ static inline int _ast_rwlock_tryrdlock(ast_rwlock_t *t, const char *name,
 {
 	int res;
 	struct ast_lock_track *lt = &t->track;
-	int canlog = strcmp(filename, "logger.c") & t->tracking;
 #ifdef HAVE_BKTR
 	struct ast_bt *bt = NULL;
 #endif
@@ -1388,8 +1381,10 @@ static inline int _ast_rwlock_tryrdlock(ast_rwlock_t *t, const char *name,
 	if (t->tracking) {
 #ifdef HAVE_BKTR
 		ast_reentrancy_lock(lt);
-		ast_bt_get_addresses(&lt->backtrace[lt->reentrancy]);
-		bt = &lt->backtrace[lt->reentrancy];
+		if (lt->reentrancy != AST_MAX_REENTRANCY) {
+			ast_bt_get_addresses(&lt->backtrace[lt->reentrancy]);
+			bt = &lt->backtrace[lt->reentrancy];
+		}
 		ast_reentrancy_unlock(lt);
 		ast_store_lock_info(AST_RDLOCK, filename, line, func, name, t, bt);
 #else
@@ -1405,9 +1400,6 @@ static inline int _ast_rwlock_tryrdlock(ast_rwlock_t *t, const char *name,
 			lt->func[lt->reentrancy] = func;
 			lt->thread[lt->reentrancy] = pthread_self();
 			lt->reentrancy++;
-		} else {
-			__ast_mutex_logger("%s line %d (%s): read lock '%s' really deep reentrancy!\n",
-					filename, line, func, name);
 		}
 		ast_reentrancy_unlock(lt);
 		if (t->tracking) {
@@ -1424,7 +1416,6 @@ static inline int _ast_rwlock_trywrlock(ast_rwlock_t *t, const char *name,
 {
 	int res;
 	struct ast_lock_track *lt= &t->track;
-	int canlog = strcmp(filename, "logger.c") & t->tracking;
 #ifdef HAVE_BKTR
 	struct ast_bt *bt = NULL;
 #endif
@@ -1448,8 +1439,10 @@ static inline int _ast_rwlock_trywrlock(ast_rwlock_t *t, const char *name,
 	if (t->tracking) {
 #ifdef HAVE_BKTR
 		ast_reentrancy_lock(lt);
-		ast_bt_get_addresses(&lt->backtrace[lt->reentrancy]);
-		bt = &lt->backtrace[lt->reentrancy];
+		if (lt->reentrancy != AST_MAX_REENTRANCY) {
+			ast_bt_get_addresses(&lt->backtrace[lt->reentrancy]);
+			bt = &lt->backtrace[lt->reentrancy];
+		}
 		ast_reentrancy_unlock(lt);
 		ast_store_lock_info(AST_WRLOCK, filename, line, func, name, t, bt);
 #else
@@ -1465,9 +1458,6 @@ static inline int _ast_rwlock_trywrlock(ast_rwlock_t *t, const char *name,
 			lt->func[lt->reentrancy] = func;
 			lt->thread[lt->reentrancy] = pthread_self();
 			lt->reentrancy++;
-		} else {
-			__ast_mutex_logger("%s line %d (%s): write lock '%s' really deep reentrancy!\n",
-					filename, line, func, name);
 		}
 		ast_reentrancy_unlock(lt);
 		if (t->tracking) {