[asterisk-commits] mmichelson: branch mmichelson/lock_backtraces r115214 - in /team/mmichelson/l...

SVN commits to the Asterisk project asterisk-commits at lists.digium.com
Fri May 2 10:17:39 CDT 2008


Author: mmichelson
Date: Fri May  2 10:17:38 2008
New Revision: 115214

URL: http://svn.digium.com/view/asterisk?view=rev&rev=115214
Log:
This adds backtrace collection to all locking calls. Some notes:

1. The __dump_backtrace function is almost a straight copy and paste
   job from the Switchvox implementation. Just giving credit where 
   credit is due.

2. I realize that rwlocks are leaking memory right now.

3. You may wonder why the backtrace collection is done where it is in
   the mutex locking functions. The reason is that it needs to be done
   before the call to ast_store_lock_info so that the information may
   be output during a core show locks command. That bit of work will be
   done in the next installment


Modified:
    team/mmichelson/lock_backtraces/include/asterisk/lock.h
    team/mmichelson/lock_backtraces/include/asterisk/logger.h
    team/mmichelson/lock_backtraces/main/logger.c

Modified: team/mmichelson/lock_backtraces/include/asterisk/lock.h
URL: http://svn.digium.com/view/asterisk/team/mmichelson/lock_backtraces/include/asterisk/lock.h?view=diff&rev=115214&r1=115213&r2=115214
==============================================================================
--- team/mmichelson/lock_backtraces/include/asterisk/lock.h (original)
+++ team/mmichelson/lock_backtraces/include/asterisk/lock.h Fri May  2 10:17:38 2008
@@ -108,9 +108,9 @@
 
 #include <errno.h>
 
-#define AST_MUTEX_INIT_VALUE { PTHREAD_MUTEX_INIT_VALUE, 1, { NULL }, { 0 }, 0, { NULL }, { 0 }, PTHREAD_MUTEX_INIT_VALUE }
+#define AST_MUTEX_INIT_VALUE { PTHREAD_MUTEX_INIT_VALUE, 1, { NULL }, { 0 }, 0, { NULL }, { 0 }, { 0 }, PTHREAD_MUTEX_INIT_VALUE }
 #define AST_MUTEX_INIT_VALUE_NOTRACKING \
-                             { PTHREAD_MUTEX_INIT_VALUE, 0, { NULL }, { 0 }, 0, { NULL }, { 0 }, PTHREAD_MUTEX_INIT_VALUE }
+                             { PTHREAD_MUTEX_INIT_VALUE, 0, { NULL }, { 0 }, 0, { NULL }, { 0 }, { 0 }, PTHREAD_MUTEX_INIT_VALUE }
 
 #define AST_MAX_REENTRANCY 10
 
@@ -125,6 +125,7 @@
 	int reentrancy;
 	const char *func[AST_MAX_REENTRANCY];
 	pthread_t thread[AST_MAX_REENTRANCY];
+	struct ast_bt backtrace[AST_MAX_REENTRANCY];
 	pthread_mutex_t reentr_mutex;
 };
 
@@ -186,7 +187,19 @@
 #define ast_remove_lock_info(ignore)
 #endif
 
-
+static inline void __dump_backtrace(ast_bt *bt)
+{
+	char **strings;
+
+	size_t i;
+
+	strings = backtrace_symbols(t->backtrace[t->reentrancy-1], t->backtrace_size[t->reentrancy-1]);
+
+	for (i = 0; i < t->backtrace_size[t->reentrancy-1]; i++)
+		__ast_mutex_logger("%s\n", strings[i]);
+
+	free(strings);
+}
 
 /*!
  * \brief log info for the current lock with ast_log().
@@ -223,6 +236,7 @@
 		p_ast_mutex->lineno[i] = 0;
 		p_ast_mutex->func[i] = NULL;
 		p_ast_mutex->thread[i] = 0;
+		p_ast_mutex->backtrace = {0,};
 	}
 
 	p_ast_mutex->reentrancy = 0;
@@ -308,6 +322,7 @@
 		ast_reentrancy_lock(t);
 		__ast_mutex_logger("%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);
+		__dump_backtrace(t->backtrace[t->reentrancy-1]);
 		ast_reentrancy_unlock(t);
 		break;
 	}
@@ -325,6 +340,7 @@
 	t->func[0] = func;
 	t->reentrancy = 0;
 	t->thread[0] = 0;
+	t->backtrace[0] = {0,};
 	ast_reentrancy_unlock(t);
 	delete_reentrancy_cs(t);
 
@@ -336,6 +352,7 @@
 {
 	int res;
 	int canlog = strcmp(filename, "logger.c") & t->track;
+	struct ast_bt *bt = NULL;
 
 #if defined(AST_MUTEX_INIT_W_CONSTRUCTORS)
 	if ((t->mutex) == ((pthread_mutex_t) PTHREAD_MUTEX_INITIALIZER)) {
@@ -352,8 +369,13 @@
 	}
 #endif /* AST_MUTEX_INIT_W_CONSTRUCTORS */
 
-	if (t->track)
+	if (t->track) {
+		ast_reentrancy_lock(t);
+		ast_bt_get_addresses(&t->backtrace[t->reentrancy]);
+		bt = &t->backtrace[t->reentrancy];
+		ast_reentrancy_unlock(t);
 		ast_store_lock_info(AST_MUTEX, filename, lineno, func, mutex_name, &t->mutex);
+	}
 
 #ifdef DETECT_DEADLOCKS
 	{
@@ -373,9 +395,11 @@
 					__ast_mutex_logger("%s line %d (%s): Deadlock? waited %d sec for mutex '%s'?\n",
 							   filename, lineno, func, (int) wait_time, mutex_name);
 					ast_reentrancy_lock(t);
+					__dump_backtrace(t->backtrace[t->reentrancy]);
 					__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);
+					__dump_backtrace(t->backtrace[t->reentrancy-1]);
 					ast_reentrancy_unlock(t);
 					reported_wait = wait_time;
 				}
@@ -424,6 +448,7 @@
 {
 	int res;
 	int canlog = strcmp(filename, "logger.c") & t->track;
+	struct ast_bt *bt = NULL;
 
 #if defined(AST_MUTEX_INIT_W_CONSTRUCTORS)
 	if ((t->mutex) == ((pthread_mutex_t) PTHREAD_MUTEX_INITIALIZER)) {
@@ -440,8 +465,13 @@
 	}
 #endif /* AST_MUTEX_INIT_W_CONSTRUCTORS */
 
-	if (t->track)
+	if (t->track) {
+		ast_reentrancy_lock(t);
+		ast_bt_get_addresses(&t->backtrace[t->reentrancy]);
+		bt = &t->backtrace[t->reentrancy];
+		ast_reentrancy_unlock(t);
 		ast_store_lock_info(AST_MUTEX, filename, lineno, func, mutex_name, &t->mutex);
+	}
 
 	if (!(res = pthread_mutex_trylock(&t->mutex))) {
 		ast_reentrancy_lock(t);
@@ -490,6 +520,7 @@
 				   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);
+		__dump_backtrace(t->backtrace[t->reentrancy-1]);
 		DO_THREAD_CRASH;
 	}
 
@@ -569,6 +600,7 @@
 				   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);
+		__dump_backtrace(t->backtrace[t->reentrancy-1]);
 		DO_THREAD_CRASH;
 	}
 
@@ -594,12 +626,15 @@
 				   filename, lineno, func, strerror(res));
 		DO_THREAD_CRASH;
 	} else {
+		struct ast_bt *bt = NULL;
 		ast_reentrancy_lock(t);
 		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();
+			ast_bt_get_addresses(&t->backtrace[t->reentrancy]);
+			bt = &t->backtrace[t->reentrancy];
 			t->reentrancy++;
 		} else {
 			__ast_mutex_logger("%s line %d (%s): '%s' really deep reentrancy!\n",
@@ -640,6 +675,7 @@
 				   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);
+		__dump_backtrace(t->backtrace[t->reentrancy-1]);
 		DO_THREAD_CRASH;
 	}
 
@@ -665,12 +701,15 @@
 				   filename, lineno, func, strerror(res));
 		DO_THREAD_CRASH;
 	} else {
+		struct ast_bt *bt = NULL;
 		ast_reentrancy_lock(t);
 		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();
+			ast_bt_get_addresses(&t->backtrace[t->reentrancy]);
+			bt = &t->backtrace[t->reentrancy];
 			t->reentrancy++;
 		} else {
 			__ast_mutex_logger("%s line %d (%s): '%s' really deep reentrancy!\n",
@@ -926,6 +965,7 @@
 	const char *file, int line, const char *func)
 {
 	int res;
+	struct ast_bt *bt = ast_bt_create();
 #ifdef AST_MUTEX_INIT_W_CONSTRUCTORS
 	int canlog = strcmp(file, "logger.c");
 	
@@ -957,6 +997,7 @@
 	const char *file, int line, const char *func)
 {
 	int res;
+	struct ast_bt *bt = ast_bt_create();
 #ifdef AST_MUTEX_INIT_W_CONSTRUCTORS
 	int canlog = strcmp(file, "logger.c");
 	
@@ -988,6 +1029,7 @@
 	const char *file, int line, const char *func)
 {
 	int res;
+	struct ast_bt *bt = ast_bt_create();
 #ifdef AST_MUTEX_INIT_W_CONSTRUCTORS
 	int canlog = strcmp(file, "logger.c");
 	
@@ -1019,6 +1061,7 @@
 	const char *file, int line, const char *func)
 {
 	int res;
+	struct ast_bt *bt = ast_bt_create();
 #ifdef AST_MUTEX_INIT_W_CONSTRUCTORS
 	int canlog = strcmp(file, "logger.c");
 	

Modified: team/mmichelson/lock_backtraces/include/asterisk/logger.h
URL: http://svn.digium.com/view/asterisk/team/mmichelson/lock_backtraces/include/asterisk/logger.h?view=diff&rev=115214&r1=115213&r2=115214
==============================================================================
--- team/mmichelson/lock_backtraces/include/asterisk/logger.h (original)
+++ team/mmichelson/lock_backtraces/include/asterisk/logger.h Fri May  2 10:17:38 2008
@@ -226,7 +226,6 @@
  */
 struct ast_bt {
 	void *addresses[AST_MAX_BT_FRAMES];
-	char **symbols;
 	int num_frames;
 	int alloced;
 };

Modified: team/mmichelson/lock_backtraces/main/logger.c
URL: http://svn.digium.com/view/asterisk/team/mmichelson/lock_backtraces/main/logger.c?view=diff&rev=115214&r1=115213&r2=115214
==============================================================================
--- team/mmichelson/lock_backtraces/main/logger.c (original)
+++ team/mmichelson/lock_backtraces/main/logger.c Fri May  2 10:17:38 2008
@@ -1142,8 +1142,7 @@
 
 	bt->alloced = 1;
 
-	if (ast_bt_populate(bt))
-		return NULL;
+	ast_bt_get_addresses(bt);
 
 	return bt;
 }
@@ -1168,10 +1167,6 @@
  */
 void *ast_bt_destroy(struct ast_bt *bt)
 {
-	if (bt->symbols) {
-		free(bt->symbols);
-	}
-
 	if (bt->alloced) {
 		ast_free(bt);
 	}




More information about the asterisk-commits mailing list