[asterisk-commits] murf: branch murf/mtxprof4 r132968 - in /team/murf/mtxprof4: channels/ includ...

SVN commits to the Asterisk project asterisk-commits at lists.digium.com
Wed Jul 23 11:47:51 CDT 2008


Author: murf
Date: Wed Jul 23 11:47:51 2008
New Revision: 132968

URL: http://svn.digium.com/view/asterisk?view=rev&rev=132968
Log:
Russell is right. should submit the last bit of debugs/etc. Working version, methinks. Let the testing be finished.

Modified:
    team/murf/mtxprof4/channels/chan_sip.c
    team/murf/mtxprof4/include/asterisk/lock.h
    team/murf/mtxprof4/include/asterisk/threadstorage.h
    team/murf/mtxprof4/main/channel.c
    team/murf/mtxprof4/main/utils.c

Modified: team/murf/mtxprof4/channels/chan_sip.c
URL: http://svn.digium.com/view/asterisk/team/murf/mtxprof4/channels/chan_sip.c?view=diff&rev=132968&r1=132967&r2=132968
==============================================================================
--- team/murf/mtxprof4/channels/chan_sip.c (original)
+++ team/murf/mtxprof4/channels/chan_sip.c Wed Jul 23 11:47:51 2008
@@ -14400,12 +14400,10 @@
 
 			/* Save Record-Route for any later requests we make on this dialogue */
 			build_route(p, req, 0);
-#ifdef WHAT_IF_WE_DONT_LOCK_THE_CHANNEL
 			if (c) {
 				/* Pre-lock the call */
 				ast_channel_lock(c);
 			}
-#endif
 		}
 	} else {
 		if (option_debug > 1 && sipdebug) {
@@ -15906,6 +15904,7 @@
 		if (p->owner) {
 			ast_channel_trylock_assign(p->owner, lockret);
 		}
+		
 		if (!p->owner || !lockret)
 			break;	/* locking succeeded */
 	

Modified: team/murf/mtxprof4/include/asterisk/lock.h
URL: http://svn.digium.com/view/asterisk/team/murf/mtxprof4/include/asterisk/lock.h?view=diff&rev=132968&r1=132967&r2=132968
==============================================================================
--- team/murf/mtxprof4/include/asterisk/lock.h (original)
+++ team/murf/mtxprof4/include/asterisk/lock.h Wed Jul 23 11:47:51 2008
@@ -528,6 +528,7 @@
 		if (t->track) {
 			ast_mark_lock_failed(t);
 		}	
+		ast_mark3(*(mtx_prof), *(start)); /* even if was busy, we should record the delay */
 	}
 	return res;
 }

Modified: team/murf/mtxprof4/include/asterisk/threadstorage.h
URL: http://svn.digium.com/view/asterisk/team/murf/mtxprof4/include/asterisk/threadstorage.h?view=diff&rev=132968&r1=132967&r2=132968
==============================================================================
--- team/murf/mtxprof4/include/asterisk/threadstorage.h (original)
+++ team/murf/mtxprof4/include/asterisk/threadstorage.h Wed Jul 23 11:47:51 2008
@@ -495,4 +495,17 @@
 }
 )
 
+/*! \brief Reset the content of a dynamic string.
+ * Useful before a series of ast_str_append.
+ */
+AST_INLINE_API(
+	void ast_dynamic_str_reset(struct ast_dynamic_str *buf),
+{
+	if (buf) {
+		if (buf->len)
+			buf->str[0] = '\0';
+	}
+}
+)
+
 #endif /* ASTERISK_THREADSTORAGE_H */

Modified: team/murf/mtxprof4/main/channel.c
URL: http://svn.digium.com/view/asterisk/team/murf/mtxprof4/main/channel.c?view=diff&rev=132968&r1=132967&r2=132968
==============================================================================
--- team/murf/mtxprof4/main/channel.c (original)
+++ team/murf/mtxprof4/main/channel.c Wed Jul 23 11:47:51 2008
@@ -1043,6 +1043,8 @@
  * shorten the retry period and possibly cause failures.
  * We should definitely go for a better scheme that is deadlock-free.
  */
+int  profnum = -1;
+
 static struct ast_channel *channel_find_locked(const struct ast_channel *prev,
 					       const char *name, const int namelen,
 					       const char *context, const char *exten)
@@ -1052,6 +1054,11 @@
 	int lockret;
 	struct ast_channel *c;
 	const struct ast_channel *_prev = prev;
+	uint64_t start_time = ast_mark2();
+
+	if (profnum == -1) {
+		profnum = ast_add_profile("channel_find_locked", 10);
+	}
 
 	for (retries = 0; retries < 200; retries++) {
 		int done;
@@ -1119,8 +1126,11 @@
 			}
 		}
 		AST_LIST_UNLOCK(&channels);
-		if (done)
+		if (done) {
+			ast_mark3(profnum, start_time);
 			return c;
+		}
+		
 		/* If we reach this point we basically tried to lock a channel and failed. Instead of
 		 * starting from the beginning of the list we can restore our saved pointer to the previous
 		 * channel and start from there.
@@ -1129,6 +1139,7 @@
 		usleep(1);	/* give other threads a chance before retrying */
 	}
 
+	ast_mark3(profnum, start_time);
 	return NULL;
 }
 

Modified: team/murf/mtxprof4/main/utils.c
URL: http://svn.digium.com/view/asterisk/team/murf/mtxprof4/main/utils.c?view=diff&rev=132968&r1=132967&r2=132968
==============================================================================
--- team/murf/mtxprof4/main/utils.c (original)
+++ team/murf/mtxprof4/main/utils.c Wed Jul 23 11:47:51 2008
@@ -521,7 +521,7 @@
 #undef pthread_mutex_destroy
 
 /*! 
- * \brief Keep track of which locks a thread holds 
+ * \brief Keep track- of which locks a thread holds 
  *
  * There is an instance of this struct for every active thread
  */
@@ -763,6 +763,101 @@
 	return "UNKNOWN";
 }
 
+static void append_lock_information(struct ast_dynamic_str **str, struct thr_lock_info *lock_info, int i)
+{
+	int j;
+	ast_mutex_t *lock;
+	ast_dynamic_str_append(str, 0, "=== ---> %sLock #%d (%s): %s %d %s %s %p (%d)\n", 
+				   lock_info->locks[i].pending > 0 ? "Waiting for " : 
+				   lock_info->locks[i].pending < 0 ? "Tried and failed to get " : "", i,
+				   lock_info->locks[i].file, 
+				   locktype2str(lock_info->locks[i].type),
+				   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);
+#ifdef HAVE_BKTR
+	append_backtrace_information(str, lock_info->locks[i].backtrace);
+#endif
+	
+	if (!lock_info->locks[i].pending || lock_info->locks[i].pending == -1)
+		return;
+	
+	/* We only have further details for mutexes right now */
+	if (lock_info->locks[i].type != AST_MUTEX)
+		return;
+	
+	lock = lock_info->locks[i].lock_addr;
+	for (j = 0; *str && j < lock->reentrancy; j++) {
+		ast_dynamic_str_append(str, 0, "=== --- ---> Locked Here: %s line %d (%s)\n",
+					   lock->file[j], lock->lineno[j], lock->func[j]);
+	}
+}
+
+/*! This function can help you find highly temporal locks; locks that happen for a 
+    short time, but at unexpected times, usually at times that create a deadlock,
+	Why is this thing locked right then? Who is locking it? Who am I fighting
+    with for this lock? 
+
+	To answer such questions, just call this routine before you would normally try
+	to aquire a lock. It doesn't do anything if the lock is not acquired. If the
+	lock is taken, it will publish a line or two to the console via ast_log().
+
+	Sometimes, the lock message is pretty uninformative. For instance, you might
+	find that the lock is being aquired deep within the astobj2 code; this tells
+	you little about higher level routines that call the astobj2 routines.
+	But, using gdb, you can set a break at the ast_log below, and for that
+	breakpoint, you can set the commands:
+	  where
+	  cont
+	which will give a stack trace and continue. -- that aught to do the job!
+
+*/
+void log_show_lock(void *this_lock_addr);
+
+void log_show_lock(void *this_lock_addr)
+{
+	struct thr_lock_info *lock_info;
+	ast_mutex_t *lockptr = this_lock_addr;
+	struct ast_dynamic_str *str;
+	int lockinfos = 0;
+	int totlocks = 0;
+	int i;
+	
+	if (!(str = ast_dynamic_str_create(4096))) {
+		ast_log(LOG_NOTICE,"Could not create str\n");
+		return;
+	}
+	for(i=0;i<lockptr->reentrancy;i++) {
+		printf("file:%s; lineno:%d; func:%s; re-ent:%d\n",lockptr->file[i], lockptr->lineno[i], lockptr->func[i], lockptr->reentrancy);
+	}
+	
+	
+	ast_log(LOG_ERROR,"Look for lock addr %p in list\n", this_lock_addr);
+	pthread_mutex_lock(&lock_infos_lock.mutex);
+	AST_LIST_TRAVERSE(&lock_infos, lock_info, entry) {
+		int i;
+		lockinfos++;
+		pthread_mutex_lock(&lock_info->lock);
+		for (i = 0; str && i < lock_info->num_locks; i++) {
+			/* ONLY show info about this particular lock, if
+			   it's acquired... */
+			totlocks++;
+			if (lock_info->locks[i].lock_addr == this_lock_addr) {
+				ast_dynamic_str_reset(str);
+				ast_dynamic_str_append(&str, 0, "Thread ID: %d (%s)\n", (int)lock_info->thread_id, lock_info->thread_name);
+				append_lock_information(&str, lock_info, i);
+				ast_log(LOG_ERROR, "%s", str->str);
+				break;
+			}
+		}
+		pthread_mutex_unlock(&lock_info->lock);
+	}
+	pthread_mutex_unlock(&lock_infos_lock.mutex);
+	ast_log(LOG_ERROR,"There are %d lock info lists, with %d locks tested.\n", lockinfos, totlocks);
+	ast_free(str);
+}
+
 static int handle_show_locks(int fd, int argc, char *argv[])
 {
 	struct thr_lock_info *lock_info;




More information about the asterisk-commits mailing list