[asterisk-commits] russell: branch russell/debug_threads r77862 - in /team/russell/debug_threads...

[SVN commits to the Asterisk project]

Author: russell
Date: Wed Aug  1 11:49:16 2007
New Revision: 77862

URL: http://svn.digium.com/view/asterisk?view=rev&rev=77862
Log:
Track the lock that a thread is waiting on as well.  Before, it only listed
the locks successfully acquired.  This should now give a pretty clear picture of
most deadlocks.

Modified:
    team/russell/debug_threads/include/asterisk/lock.h
    team/russell/debug_threads/utils.c

Modified: team/russell/debug_threads/include/asterisk/lock.h
URL: http://svn.digium.com/view/asterisk/team/russell/debug_threads/include/asterisk/lock.h?view=diff&rev=77862&r1=77861&r2=77862
==============================================================================
--- team/russell/debug_threads/include/asterisk/lock.h (original)
+++ team/russell/debug_threads/include/asterisk/lock.h Wed Aug  1 11:49:16 2007
@@ -219,6 +219,8 @@
 void ast_store_lock_info(const char *filename, int line_num, 
 	const char *func, const char *lock_name, void *lock_addr);
 
+void ast_mark_lock_acquired(void);
+
 void ast_remove_lock_info(void *lock_addr);
 
 static inline int __ast_pthread_mutex_lock(const char *filename, int lineno, const char *func,
@@ -226,6 +228,8 @@
 {
 	int res;
 	int canlog = strcmp(filename, "logger.c");
+
+	ast_store_lock_info(filename, lineno, func, mutex_name, &t->mutex);
 
 #if defined(AST_MUTEX_INIT_W_CONSTRUCTORS) || defined(AST_MUTEX_INIT_ON_FIRST_USE)
 	if ((t->mutex) == ((pthread_mutex_t) PTHREAD_MUTEX_INITIALIZER)) {
@@ -261,7 +265,7 @@
 #endif /* DETECT_DEADLOCKS */
 
 	if (!res) {
-		ast_store_lock_info(filename, lineno, func, mutex_name, &t->mutex);
+		ast_mark_lock_acquired();
 		if (t->reentrancy < AST_MAX_REENTRANCY) {
 			t->file[t->reentrancy] = filename;
 			t->lineno[t->reentrancy] = lineno;
@@ -273,6 +277,7 @@
 							   filename, lineno, func, mutex_name);
 		}
 	} else {
+		ast_remove_lock_info(&t->mutex);
 		__ast_mutex_logger("%s line %d (%s): Error obtaining mutex: %s\n",
 				   filename, lineno, func, strerror(res));
 #ifdef THREAD_CRASH
@@ -300,8 +305,10 @@
 	}
 #endif /* defined(AST_MUTEX_INIT_W_CONSTRUCTORS) || defined(AST_MUTEX_INIT_ON_FIRST_USE) */
 
+	ast_store_lock_info(filename, lineno, func, mutex_name, &t->mutex);
+
 	if (!(res = pthread_mutex_trylock(&t->mutex))) {
-		ast_store_lock_info(filename, lineno, func, mutex_name, &t->mutex);
+		ast_mark_lock_acquired();
 		if (t->reentrancy < AST_MAX_REENTRANCY) {
 			t->file[t->reentrancy] = filename;
 			t->lineno[t->reentrancy] = lineno;
@@ -312,6 +319,8 @@
 			__ast_mutex_logger("%s line %d (%s): '%s' really deep reentrancy!\n",
 							   filename, lineno, func, mutex_name);
 		}
+	} else {
+		ast_remove_lock_info(&t->mutex);
 	}
 
 	return res;

Modified: team/russell/debug_threads/utils.c
URL: http://svn.digium.com/view/asterisk/team/russell/debug_threads/utils.c?view=diff&rev=77862&r1=77861&r2=77862
==============================================================================
--- team/russell/debug_threads/utils.c (original)
+++ team/russell/debug_threads/utils.c Wed Aug  1 11:49:16 2007
@@ -520,6 +520,8 @@
 		const char *lock_name;
 		void *lock_addr;
 		int times_locked;
+		/*! This thread is waiting on this lock */
+		unsigned int pending:1;
 	} locks[AST_MAX_LOCKS];
 	/*! This is the number of locks currently held by this thread.
 	 *  The index (num_locks - 1) has the info on the last one in the
@@ -568,7 +570,8 @@
  *
  * This function gets called in ast_mutex_lock() and ast_mutex_trylock() so
  * that information about this lock can be stored in this thread's
- * lock info struct.
+ * lock info struct.  The lock is marked as pending as the thread is waiting
+ * on the lock.  ast_mark_lock_acquired() will mark it as held by this thread.
  */
 void ast_store_lock_info(const char *filename, int line_num, 
 	const char *func, const char *lock_name, void *lock_addr)
@@ -603,8 +606,25 @@
 	lock_info->locks[i].lock_name = lock_name;
 	lock_info->locks[i].lock_addr = lock_addr;
 	lock_info->locks[i].times_locked = 1;
+	lock_info->locks[i].pending = 1;
 	lock_info->num_locks++;
 
+	pthread_mutex_unlock(&lock_info->lock);
+}
+
+/*!
+ * \brief Mark the last lock as acquired
+ */
+void ast_mark_lock_acquired(void)
+{
+	struct thr_lock_info *lock_info;
+	int i;
+
+	if (!(lock_info = ast_threadstorage_get(&thread_lock_info, sizeof(*lock_info))))
+		return;
+
+	pthread_mutex_lock(&lock_info->lock);
+	lock_info->locks[lock_info->num_locks - 1].pending = 0;
 	pthread_mutex_unlock(&lock_info->lock);
 }
 
@@ -671,7 +691,8 @@
 			lock_info->thread_name);
 		pthread_mutex_lock(&lock_info->lock);
 		for (i = 0; i < lock_info->num_locks; i++) {
-			ast_cli(fd, "=== ---> Lock #%d: %s %d %s %s %p (%d)\n", i,
+			ast_cli(fd, "=== ---> %sLock #%d: %s %d %s %s %p (%d)\n", 
+				lock_info->locks[i].pending ? "Waiting for " : "", i,
 				lock_info->locks[i].file, lock_info->locks[i].line_num,
 				lock_info->locks[i].func, lock_info->locks[i].lock_name,
 				lock_info->locks[i].lock_addr,