[asterisk-commits] russell: branch 1.4 r78095 - in /branches/1.4: include/asterisk/ main/

SVN commits to the Asterisk project asterisk-commits at lists.digium.com
Fri Aug 3 14:39:50 CDT 2007


Author: russell
Date: Fri Aug  3 14:39:49 2007
New Revision: 78095

URL: http://svn.digium.com/view/asterisk?view=rev&rev=78095
Log:
Add some improvements to lock debugging.  These changes take effect
with DEBUG_THREADS enabled and provide the following:

 * This will keep track of which locks are held by which thread as well as
   which lock a thread is waiting for in a thread-local data structure.  A
   reference to this structure is available on the stack in the dummy_start()
   function, which is the common entry point for all threads.  This information
   can be easily retrieved using gdb if you switch to the dummy_start() stack
   frame of any thread and print the contents of the lock_info variable.

 * All of the thread-local structures for keeping track of this lock information
   are also stored in a list so that the information can be dumped to the CLI
   using the "core show locks" CLI command.  This introduces a little bit of a
   performance hit as it requires additional underlying locking operations
   inside of every lock/unlock on an ast_mutex.  However, the benefits of
   having this information available at the CLI is huge, especially considering
   this is only done in DEBUG_THREADS mode.  It means that in most cases where
   we debug deadlocks, we no longer have to request access to the machine to
   analyze the contents of ast_mutex_t structures.  We can now just ask them
   to get the output of "core show locks", which gives us all of the information
   we needed in most cases.

I also had to make some additional changes to astmm.c to make this work when
both MALLOC_DEBUG and DEBUG_THREADS are enabled.  I disabled tracking of one
of the locks in astmm.c because it gets used inside the replacement memory
allocation routines, and the lock tracking code allocates memory.  This caused
infinite recursion.

Modified:
    branches/1.4/include/asterisk/lock.h
    branches/1.4/main/astmm.c
    branches/1.4/main/utils.c

Modified: branches/1.4/include/asterisk/lock.h
URL: http://svn.digium.com/view/asterisk/branches/1.4/include/asterisk/lock.h?view=diff&rev=78095&r1=78094&r2=78095
==============================================================================
--- branches/1.4/include/asterisk/lock.h (original)
+++ branches/1.4/include/asterisk/lock.h Fri Aug  3 14:39:49 2007
@@ -103,12 +103,16 @@
 #include <stdio.h>
 #include <unistd.h>
 
-#define AST_MUTEX_INIT_VALUE { PTHREAD_MUTEX_INIT_VALUE, { NULL }, { 0 }, 0, { NULL }, { 0 } }
+#define AST_MUTEX_INIT_VALUE { PTHREAD_MUTEX_INIT_VALUE, 1, { NULL }, { 0 }, 0, { NULL }, { 0 } }
+#define AST_MUTEX_INIT_VALUE_NOTRACKING \
+                             { PTHREAD_MUTEX_INIT_VALUE, 0, { NULL }, { 0 }, 0, { NULL }, { 0 } }
 
 #define AST_MAX_REENTRANCY 10
 
 struct ast_mutex_info {
 	pthread_mutex_t mutex;
+	/*! Track which thread holds this lock */
+	unsigned int track:1;
 	const char *file[AST_MAX_REENTRANCY];
 	int lineno[AST_MAX_REENTRANCY];
 	int reentrancy;
@@ -121,6 +125,30 @@
 typedef pthread_cond_t ast_cond_t;
 
 static pthread_mutex_t empty_mutex;
+
+/*!
+ * \brief Store lock info for the current thread
+ *
+ * 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.  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);
+
+/*!
+ * \brief Mark the last lock as acquired
+ */
+void ast_mark_lock_acquired(void);
+
+/*!
+ * \brief remove lock info for the current thread
+ *
+ * this gets called by ast_mutex_unlock so that information on the lock can
+ * be removed from the current thread's lock info struct.
+ */
+void ast_remove_lock_info(void *lock_addr);
 
 static void __attribute__((constructor)) init_empty_mutex(void)
 {
@@ -216,6 +244,9 @@
 {
 	int res;
 	int canlog = strcmp(filename, "logger.c");
+
+	if (t->track)
+		ast_store_lock_info(filename, lineno, func, mutex_name, &t->mutex);
 
 #if defined(AST_MUTEX_INIT_W_CONSTRUCTORS)
 	if ((t->mutex) == ((pthread_mutex_t) PTHREAD_MUTEX_INITIALIZER)) {
@@ -261,6 +292,8 @@
 #endif /* DETECT_DEADLOCKS */
 
 	if (!res) {
+		if (t->track)
+			ast_mark_lock_acquired();
 		if (t->reentrancy < AST_MAX_REENTRANCY) {
 			t->file[t->reentrancy] = filename;
 			t->lineno[t->reentrancy] = lineno;
@@ -272,6 +305,8 @@
 							   filename, lineno, func, mutex_name);
 		}
 	} else {
+		if (t->track)
+			ast_remove_lock_info(&t->mutex);
 		__ast_mutex_logger("%s line %d (%s): Error obtaining mutex: %s\n",
 				   filename, lineno, func, strerror(res));
 		DO_THREAD_CRASH;
@@ -294,7 +329,145 @@
 	}
 #endif /* AST_MUTEX_INIT_W_CONSTRUCTORS */
 
+	if (t->track)
+		ast_store_lock_info(filename, lineno, func, mutex_name, &t->mutex);
+
 	if (!(res = pthread_mutex_trylock(&t->mutex))) {
+		if (t->track)
+			ast_mark_lock_acquired();
+		if (t->reentrancy < AST_MAX_REENTRANCY) {
+			t->file[t->reentrancy] = filename;
+			t->lineno[t->reentrancy] = lineno;
+			t->func[t->reentrancy] = func;
+			t->thread[t->reentrancy] = pthread_self();
+			t->reentrancy++;
+		} else {
+			__ast_mutex_logger("%s line %d (%s): '%s' really deep reentrancy!\n",
+					   filename, lineno, func, mutex_name);
+		}
+	} else if (t->track) {
+			ast_remove_lock_info(&t->mutex);
+	}
+
+	return res;
+}
+
+static inline int __ast_pthread_mutex_unlock(const char *filename, int lineno, const char *func,
+					     const char *mutex_name, ast_mutex_t *t)
+{
+	int res;
+	int canlog = strcmp(filename, "logger.c");
+
+#ifdef AST_MUTEX_INIT_W_CONSTRUCTORS
+	if ((t->mutex) == ((pthread_mutex_t) PTHREAD_MUTEX_INITIALIZER)) {
+		__ast_mutex_logger("%s line %d (%s): Error: mutex '%s' is uninitialized.\n",
+				   filename, lineno, func, mutex_name);
+	}
+#endif
+
+	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",
+				   filename, lineno, func, mutex_name);
+		__ast_mutex_logger("%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);
+		DO_THREAD_CRASH;
+	}
+
+	if (--t->reentrancy < 0) {
+		__ast_mutex_logger("%s line %d (%s): mutex '%s' freed more times than we've locked!\n",
+				   filename, lineno, func, mutex_name);
+		t->reentrancy = 0;
+	}
+
+	if (t->reentrancy < AST_MAX_REENTRANCY) {
+		t->file[t->reentrancy] = NULL;
+		t->lineno[t->reentrancy] = 0;
+		t->func[t->reentrancy] = NULL;
+		t->thread[t->reentrancy] = 0;
+	}
+
+	if (t->track)
+		ast_remove_lock_info(&t->mutex);
+
+	if ((res = pthread_mutex_unlock(&t->mutex))) {
+		__ast_mutex_logger("%s line %d (%s): Error releasing mutex: %s\n", 
+				   filename, lineno, func, strerror(res));
+		DO_THREAD_CRASH;
+	}
+
+	return res;
+}
+
+static inline int __ast_cond_init(const char *filename, int lineno, const char *func,
+				  const char *cond_name, ast_cond_t *cond, pthread_condattr_t *cond_attr)
+{
+	return pthread_cond_init(cond, cond_attr);
+}
+
+static inline int __ast_cond_signal(const char *filename, int lineno, const char *func,
+				    const char *cond_name, ast_cond_t *cond)
+{
+	return pthread_cond_signal(cond);
+}
+
+static inline int __ast_cond_broadcast(const char *filename, int lineno, const char *func,
+				       const char *cond_name, ast_cond_t *cond)
+{
+	return pthread_cond_broadcast(cond);
+}
+
+static inline int __ast_cond_destroy(const char *filename, int lineno, const char *func,
+				     const char *cond_name, ast_cond_t *cond)
+{
+	return pthread_cond_destroy(cond);
+}
+
+static inline int __ast_cond_wait(const char *filename, int lineno, const char *func,
+				  const char *cond_name, const char *mutex_name,
+				  ast_cond_t *cond, ast_mutex_t *t)
+{
+	int res;
+	int canlog = strcmp(filename, "logger.c");
+
+#ifdef AST_MUTEX_INIT_W_CONSTRUCTORS
+	if ((t->mutex) == ((pthread_mutex_t) PTHREAD_MUTEX_INITIALIZER)) {
+		__ast_mutex_logger("%s line %d (%s): Error: mutex '%s' is uninitialized.\n",
+				   filename, lineno, func, mutex_name);
+	}
+#endif
+
+	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",
+				   filename, lineno, func, mutex_name);
+		__ast_mutex_logger("%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);
+		DO_THREAD_CRASH;
+	}
+
+	if (--t->reentrancy < 0) {
+		__ast_mutex_logger("%s line %d (%s): mutex '%s' freed more times than we've locked!\n",
+				   filename, lineno, func, mutex_name);
+		t->reentrancy = 0;
+	}
+
+	if (t->reentrancy < AST_MAX_REENTRANCY) {
+		t->file[t->reentrancy] = NULL;
+		t->lineno[t->reentrancy] = 0;
+		t->func[t->reentrancy] = NULL;
+		t->thread[t->reentrancy] = 0;
+	}
+
+	if (t->track)
+		ast_remove_lock_info(&t->mutex);
+
+	if ((res = pthread_cond_wait(cond, &t->mutex))) {
+		__ast_mutex_logger("%s line %d (%s): Error waiting on condition mutex '%s'\n", 
+				   filename, lineno, func, strerror(res));
+		DO_THREAD_CRASH;
+	} else {
+		if (t->track)
+			ast_store_lock_info(filename, lineno, func, mutex_name, &t->mutex);
+
 		if (t->reentrancy < AST_MAX_REENTRANCY) {
 			t->file[t->reentrancy] = filename;
 			t->lineno[t->reentrancy] = lineno;
@@ -310,8 +483,9 @@
 	return res;
 }
 
-static inline int __ast_pthread_mutex_unlock(const char *filename, int lineno, const char *func,
-					     const char *mutex_name, ast_mutex_t *t)
+static inline int __ast_cond_timedwait(const char *filename, int lineno, const char *func,
+				       const char *cond_name, const char *mutex_name, ast_cond_t *cond,
+				       ast_mutex_t *t, const struct timespec *abstime)
 {
 	int res;
 	int canlog = strcmp(filename, "logger.c");
@@ -344,79 +518,17 @@
 		t->thread[t->reentrancy] = 0;
 	}
 
-	if ((res = pthread_mutex_unlock(&t->mutex))) {
-		__ast_mutex_logger("%s line %d (%s): Error releasing mutex: %s\n", 
-				   filename, lineno, func, strerror(res));
-		DO_THREAD_CRASH;
-	}
-
-	return res;
-}
-
-static inline int __ast_cond_init(const char *filename, int lineno, const char *func,
-				  const char *cond_name, ast_cond_t *cond, pthread_condattr_t *cond_attr)
-{
-	return pthread_cond_init(cond, cond_attr);
-}
-
-static inline int __ast_cond_signal(const char *filename, int lineno, const char *func,
-				    const char *cond_name, ast_cond_t *cond)
-{
-	return pthread_cond_signal(cond);
-}
-
-static inline int __ast_cond_broadcast(const char *filename, int lineno, const char *func,
-				       const char *cond_name, ast_cond_t *cond)
-{
-	return pthread_cond_broadcast(cond);
-}
-
-static inline int __ast_cond_destroy(const char *filename, int lineno, const char *func,
-				     const char *cond_name, ast_cond_t *cond)
-{
-	return pthread_cond_destroy(cond);
-}
-
-static inline int __ast_cond_wait(const char *filename, int lineno, const char *func,
-				  const char *cond_name, const char *mutex_name,
-				  ast_cond_t *cond, ast_mutex_t *t)
-{
-	int res;
-	int canlog = strcmp(filename, "logger.c");
-
-#ifdef AST_MUTEX_INIT_W_CONSTRUCTORS
-	if ((t->mutex) == ((pthread_mutex_t) PTHREAD_MUTEX_INITIALIZER)) {
-		__ast_mutex_logger("%s line %d (%s): Error: mutex '%s' is uninitialized.\n",
-				   filename, lineno, func, mutex_name);
-	}
-#endif
-
-	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",
-				   filename, lineno, func, mutex_name);
-		__ast_mutex_logger("%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);
-		DO_THREAD_CRASH;
-	}
-
-	if (--t->reentrancy < 0) {
-		__ast_mutex_logger("%s line %d (%s): mutex '%s' freed more times than we've locked!\n",
-				   filename, lineno, func, mutex_name);
-		t->reentrancy = 0;
-	}
-
-	if (t->reentrancy < AST_MAX_REENTRANCY) {
-		t->file[t->reentrancy] = NULL;
-		t->lineno[t->reentrancy] = 0;
-		t->func[t->reentrancy] = NULL;
-		t->thread[t->reentrancy] = 0;
-	}
-
-	if ((res = pthread_cond_wait(cond, &t->mutex))) {
+	if (t->track)
+		ast_remove_lock_info(&t->mutex);
+
+	if ((res = pthread_cond_timedwait(cond, &t->mutex, abstime)) && (res != ETIMEDOUT)) {
 		__ast_mutex_logger("%s line %d (%s): Error waiting on condition mutex '%s'\n", 
 				   filename, lineno, func, strerror(res));
 		DO_THREAD_CRASH;
 	} else {
+		if (t->track)
+			ast_store_lock_info(filename, lineno, func, mutex_name, &t->mutex);
+
 		if (t->reentrancy < AST_MAX_REENTRANCY) {
 			t->file[t->reentrancy] = filename;
 			t->lineno[t->reentrancy] = lineno;
@@ -432,61 +544,6 @@
 	return res;
 }
 
-static inline int __ast_cond_timedwait(const char *filename, int lineno, const char *func,
-				       const char *cond_name, const char *mutex_name, ast_cond_t *cond,
-				       ast_mutex_t *t, const struct timespec *abstime)
-{
-	int res;
-	int canlog = strcmp(filename, "logger.c");
-
-#ifdef AST_MUTEX_INIT_W_CONSTRUCTORS
-	if ((t->mutex) == ((pthread_mutex_t) PTHREAD_MUTEX_INITIALIZER)) {
-		__ast_mutex_logger("%s line %d (%s): Error: mutex '%s' is uninitialized.\n",
-				   filename, lineno, func, mutex_name);
-	}
-#endif
-
-	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",
-				   filename, lineno, func, mutex_name);
-		__ast_mutex_logger("%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);
-		DO_THREAD_CRASH;
-	}
-
-	if (--t->reentrancy < 0) {
-		__ast_mutex_logger("%s line %d (%s): mutex '%s' freed more times than we've locked!\n",
-				   filename, lineno, func, mutex_name);
-		t->reentrancy = 0;
-	}
-
-	if (t->reentrancy < AST_MAX_REENTRANCY) {
-		t->file[t->reentrancy] = NULL;
-		t->lineno[t->reentrancy] = 0;
-		t->func[t->reentrancy] = NULL;
-		t->thread[t->reentrancy] = 0;
-	}
-
-	if ((res = pthread_cond_timedwait(cond, &t->mutex, abstime)) && (res != ETIMEDOUT)) {
-		__ast_mutex_logger("%s line %d (%s): Error waiting on condition mutex '%s'\n", 
-				   filename, lineno, func, strerror(res));
-		DO_THREAD_CRASH;
-	} else {
-		if (t->reentrancy < AST_MAX_REENTRANCY) {
-			t->file[t->reentrancy] = filename;
-			t->lineno[t->reentrancy] = lineno;
-			t->func[t->reentrancy] = func;
-			t->thread[t->reentrancy] = pthread_self();
-			t->reentrancy++;
-		} else {
-			__ast_mutex_logger("%s line %d (%s): '%s' really deep reentrancy!\n",
-							   filename, lineno, func, mutex_name);
-		}
-	}
-
-	return res;
-}
-
 #define ast_mutex_destroy(a) __ast_pthread_mutex_destroy(__FILE__, __LINE__, __PRETTY_FUNCTION__, #a, a)
 #define ast_mutex_lock(a) __ast_pthread_mutex_lock(__FILE__, __LINE__, __PRETTY_FUNCTION__, #a, a)
 #define ast_mutex_unlock(a) __ast_pthread_mutex_unlock(__FILE__, __LINE__, __PRETTY_FUNCTION__, #a, a)
@@ -574,8 +631,8 @@
 #if defined(AST_MUTEX_INIT_W_CONSTRUCTORS)
 /* If AST_MUTEX_INIT_W_CONSTRUCTORS is defined, use file scope
  constructors/destructors to create/destroy mutexes.  */
-#define __AST_MUTEX_DEFINE(scope, mutex) \
-	scope ast_mutex_t mutex = AST_MUTEX_INIT_VALUE; \
+#define __AST_MUTEX_DEFINE(scope, mutex, init_val) \
+	scope ast_mutex_t mutex = init_val; \
 static void  __attribute__ ((constructor)) init_##mutex(void) \
 { \
 	ast_mutex_init(&mutex); \
@@ -586,8 +643,8 @@
 }
 #else /* !AST_MUTEX_INIT_W_CONSTRUCTORS */
 /* By default, use static initialization of mutexes. */ 
-#define __AST_MUTEX_DEFINE(scope, mutex) \
-	scope ast_mutex_t mutex = AST_MUTEX_INIT_VALUE
+#define __AST_MUTEX_DEFINE(scope, mutex, init_val) \
+	scope ast_mutex_t mutex = init_val
 #endif /* AST_MUTEX_INIT_W_CONSTRUCTORS */
 
 #define pthread_mutex_t use_ast_mutex_t_instead_of_pthread_mutex_t
@@ -604,7 +661,8 @@
 #define pthread_cond_wait use_ast_cond_wait_instead_of_pthread_cond_wait
 #define pthread_cond_timedwait use_ast_cond_timedwait_instead_of_pthread_cond_timedwait
 
-#define AST_MUTEX_DEFINE_STATIC(mutex) __AST_MUTEX_DEFINE(static, mutex)
+#define AST_MUTEX_DEFINE_STATIC(mutex) __AST_MUTEX_DEFINE(static, mutex, AST_MUTEX_INIT_VALUE)
+#define AST_MUTEX_DEFINE_STATIC_NOTRACKING(mutex) __AST_MUTEX_DEFINE(static, mutex, AST_MUTEX_INIT_VALUE_NOTRACKING)
 
 #define AST_MUTEX_INITIALIZER __use_AST_MUTEX_DEFINE_STATIC_rather_than_AST_MUTEX_INITIALIZER__
 
@@ -621,11 +679,11 @@
 	pthread_rwlockattr_t attr;
 
 	pthread_rwlockattr_init(&attr);
-	
+
 #ifdef HAVE_PTHREAD_RWLOCK_PREFER_WRITER_NP
 	pthread_rwlockattr_setkind_np(&attr, PTHREAD_RWLOCK_PREFER_WRITER_NP);
 #endif
-	
+
 	return pthread_rwlock_init(prwlock, &attr);
 }
 

Modified: branches/1.4/main/astmm.c
URL: http://svn.digium.com/view/asterisk/branches/1.4/main/astmm.c?view=diff&rev=78095&r1=78094&r2=78095
==============================================================================
--- branches/1.4/main/astmm.c (original)
+++ branches/1.4/main/astmm.c Fri Aug  3 14:39:49 2007
@@ -81,7 +81,7 @@
 #define HASH(a) \
 	(((unsigned long)(a)) % SOME_PRIME)
 	
-AST_MUTEX_DEFINE_STATIC(reglock);
+AST_MUTEX_DEFINE_STATIC_NOTRACKING(reglock);
 AST_MUTEX_DEFINE_STATIC(showmemorylock);
 
 #define astmm_log(...)                               \

Modified: branches/1.4/main/utils.c
URL: http://svn.digium.com/view/asterisk/branches/1.4/main/utils.c?view=diff&rev=78095&r1=78094&r2=78095
==============================================================================
--- branches/1.4/main/utils.c (original)
+++ branches/1.4/main/utils.c Fri Aug  3 14:39:49 2007
@@ -46,6 +46,8 @@
 #include "asterisk/md5.h"
 #include "asterisk/sha1.h"
 #include "asterisk/options.h"
+#include "asterisk/cli.h"
+#include "asterisk/linkedlists.h"
 
 #define AST_API_MODULE		/* ensure that inlinable API functions will be built in this module if required */
 #include "asterisk/strings.h"
@@ -500,17 +502,228 @@
 	return inet_ntop(AF_INET, &ia, buf, INET_ADDRSTRLEN);
 }
 
-int ast_utils_init(void)
-{
-	base64_init();
-	return 0;
-}
-
 #ifndef __linux__
 #undef pthread_create /* For ast_pthread_create function only */
 #endif /* !__linux__ */
 
 #if !defined(LOW_MEMORY)
+
+#ifdef DEBUG_THREADS
+
+/*! \brief A reasonable maximum number of locks a thread would be holding ... */
+#define AST_MAX_LOCKS 16
+
+/* Allow direct use of pthread_mutex_t and friends */
+#undef pthread_mutex_t
+#undef pthread_mutex_lock
+#undef pthread_mutex_unlock
+#undef pthread_mutex_init
+#undef pthread_mutex_destroy
+
+/*! 
+ * \brief Keep track of which locks a thread holds 
+ *
+ * There is an instance of this struct for every active thread
+ */
+struct thr_lock_info {
+	/*! The thread's ID */
+	pthread_t thread_id;
+	/*! The thread name which includes where the thread was started */
+	const char *thread_name;
+	/*! This is the actual container of info for what locks this thread holds */
+	struct {
+		const char *file;
+		int line_num;
+		const char *func;
+		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
+	 *  locks member */
+	unsigned int num_locks;
+	/*! Protects the contents of the locks member 
+	 * Intentionally not ast_mutex_t */
+	pthread_mutex_t lock;
+	AST_LIST_ENTRY(thr_lock_info) entry;
+};
+
+/*! 
+ * \brief Locked when accessing the lock_infos list 
+ */
+AST_MUTEX_DEFINE_STATIC(lock_infos_lock);
+/*!
+ * \brief A list of each thread's lock info 
+ */
+static AST_LIST_HEAD_NOLOCK_STATIC(lock_infos, thr_lock_info);
+
+/*!
+ * \brief Destroy a thread's lock info
+ *
+ * This gets called automatically when the thread stops
+ */
+static void lock_info_destroy(void *data)
+{
+	struct thr_lock_info *lock_info = data;
+
+	pthread_mutex_lock(&lock_infos_lock.mutex);
+	AST_LIST_REMOVE(&lock_infos, lock_info, entry);
+	pthread_mutex_unlock(&lock_infos_lock.mutex);
+
+	pthread_mutex_destroy(&lock_info->lock);
+	free((void *) lock_info->thread_name);
+	free(lock_info);
+}
+
+/*!
+ * \brief The thread storage key for per-thread lock info
+ */
+AST_THREADSTORAGE_CUSTOM(thread_lock_info, thread_lock_info_init, lock_info_destroy);
+
+void ast_store_lock_info(const char *filename, int line_num, 
+	const char *func, const char *lock_name, void *lock_addr)
+{
+	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);
+
+	for (i = 0; i < lock_info->num_locks; i++) {
+		if (lock_info->locks[i].lock_addr == lock_addr) {
+			lock_info->locks[i].times_locked++;
+			pthread_mutex_unlock(&lock_info->lock);
+			return;
+		}
+	}
+
+	if (lock_info->num_locks == AST_MAX_LOCKS) {
+		/* Can't use ast_log here, because it will cause infinite recursion */
+		fprintf(stderr, "XXX ERROR XXX A thread holds more locks than '%d'."
+			"  Increase AST_MAX_LOCKS!\n", AST_MAX_LOCKS);
+		pthread_mutex_unlock(&lock_info->lock);
+		return;
+	}
+	
+	lock_info->locks[i].file = filename;
+	lock_info->locks[i].line_num = line_num;
+	lock_info->locks[i].func = func;
+	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);
+}
+
+void ast_mark_lock_acquired(void)
+{
+	struct thr_lock_info *lock_info;
+
+	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);
+}
+
+void ast_remove_lock_info(void *lock_addr)
+{
+	struct thr_lock_info *lock_info;
+	int i = 0;
+
+	if (!(lock_info = ast_threadstorage_get(&thread_lock_info, sizeof(*lock_info))))
+		return;
+
+	pthread_mutex_lock(&lock_info->lock);
+
+	for (i = lock_info->num_locks - 1; i >= 0; i--) {
+		if (lock_info->locks[i].lock_addr == lock_addr)
+			break;
+	}
+
+	if (i == -1) {
+		/* Lock not found :( */
+		pthread_mutex_unlock(&lock_info->lock);
+		return;
+	}
+
+	if (lock_info->locks[i].times_locked > 1) {
+		lock_info->locks[i].times_locked--;
+		pthread_mutex_unlock(&lock_info->lock);
+		return;
+	}
+
+	if (i < lock_info->num_locks - 1) {
+		/* Not the last one ... *should* be rare! */
+		memmove(&lock_info->locks[i], &lock_info->locks[i + 1], 
+			(lock_info->num_locks - (i + 1)) * sizeof(lock_info->locks[0]));
+	}
+
+	lock_info->num_locks--;
+
+	pthread_mutex_unlock(&lock_info->lock);
+}
+
+static int handle_show_locks(int fd, int argc, char *argv[])
+{
+	struct thr_lock_info *lock_info;
+
+	ast_cli(fd, "\n" 
+	            "=======================================================================\n"
+	            "=== Currently Held Locks ==============================================\n"
+	            "=======================================================================\n"
+	            "===\n"
+				"=== <file> <line num> <function> <lock name> <lock addr> (times locked)\n"
+				"===\n");
+
+	pthread_mutex_lock(&lock_infos_lock.mutex);
+	AST_LIST_TRAVERSE(&lock_infos, lock_info, entry) {
+		int i;
+		ast_cli(fd, "=== Thread ID: %d (%s)\n", (int) lock_info->thread_id,
+			lock_info->thread_name);
+		pthread_mutex_lock(&lock_info->lock);
+		for (i = 0; i < lock_info->num_locks; 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, 
+				lock_info->locks[i].times_locked);
+		}
+		pthread_mutex_unlock(&lock_info->lock);
+		ast_cli(fd, "=== -------------------------------------------------------------------\n"
+		            "===\n");
+	}
+	pthread_mutex_unlock(&lock_infos_lock.mutex);
+
+	ast_cli(fd, "=======================================================================\n"
+	            "\n");
+
+	return 0;
+}
+
+static char show_locks_help[] =
+"Usage: core show locks\n"
+"       This command is for lock debugging.  It prints out which locks\n"
+"are owned by each active thread.\n";
+
+static struct ast_cli_entry utils_cli[] = {
+	{ { "core", "show", "locks", NULL }, handle_show_locks,
+	  "Show which locks are locked by which thread", show_locks_help },
+};
+
+#endif /* DEBUG_THREADS */
+
+
+
 /*
  * support for 'show threads'. The start routine is wrapped by
  * dummy_start(), so that ast_register_thread() and
@@ -533,6 +746,9 @@
 {
 	void *ret;
 	struct thr_arg a = *((struct thr_arg *) data);	/* make a local copy */
+#ifdef DEBUG_THREADS
+	struct thr_lock_info *lock_info;
+#endif
 
 	/* note that even though data->name is a pointer to allocated memory,
 	   we are not freeing it here because ast_register_thread is going to
@@ -542,7 +758,22 @@
 	free(data);
 	ast_register_thread(a.name);
 	pthread_cleanup_push(ast_unregister_thread, (void *) pthread_self());
+
+#ifdef DEBUG_THREADS
+	if (!(lock_info = ast_threadstorage_get(&thread_lock_info, sizeof(*lock_info))))
+		return NULL;
+
+	lock_info->thread_id = pthread_self();
+	lock_info->thread_name = strdup(a.name);
+	pthread_mutex_init(&lock_info->lock, NULL);
+
+	pthread_mutex_lock(&lock_infos_lock.mutex); /* Intentionally not the wrapper */
+	AST_LIST_INSERT_TAIL(&lock_infos, lock_info, entry);
+	pthread_mutex_unlock(&lock_infos_lock.mutex); /* Intentionally not the wrapper */
+#endif /* DEBUG_THREADS */
+
 	ret = a.start_routine(a.data);
+
 	pthread_cleanup_pop(1);
 
 	return ret;
@@ -1011,3 +1242,14 @@
 		ast_log(LOG_WARNING, "Unable to disable PMTU discovery. Large UDP packets may fail to be delivered when sent from this socket.\n");
 #endif /* HAVE_IP_MTU_DISCOVER */
 }
+
+int ast_utils_init(void)
+{
+	base64_init();
+#ifdef DEBUG_THREADS
+	ast_cli_register_multiple(utils_cli, sizeof(utils_cli) / sizeof(utils_cli[0]));
+#endif
+	return 0;
+}
+
+




More information about the asterisk-commits mailing list