[asterisk-commits] murf: branch murf/mtxprof r127243 - in /team/murf/mtxprof: channels/ funcs/ i...

SVN commits to the Asterisk project asterisk-commits at lists.digium.com
Tue Jul 1 18:09:54 CDT 2008


Author: murf
Date: Tue Jul  1 18:09:54 2008
New Revision: 127243

URL: http://svn.digium.com/view/asterisk?view=rev&rev=127243
Log:
I want to see, when a lock is requested, how many times the lock was busy, and who had it already; This work covers the first half. I'm filling in the intersection of MTX_PROF and DEBUG_THREADS.

Modified:
    team/murf/mtxprof/channels/chan_agent.c
    team/murf/mtxprof/channels/chan_dahdi.c
    team/murf/mtxprof/channels/chan_iax2.c
    team/murf/mtxprof/channels/chan_local.c
    team/murf/mtxprof/channels/chan_mgcp.c
    team/murf/mtxprof/channels/chan_sip.c
    team/murf/mtxprof/funcs/func_lock.c
    team/murf/mtxprof/include/asterisk.h
    team/murf/mtxprof/include/asterisk/linkedlists.h
    team/murf/mtxprof/include/asterisk/lock.h
    team/murf/mtxprof/main/asterisk.c
    team/murf/mtxprof/main/astobj2.c
    team/murf/mtxprof/main/channel.c
    team/murf/mtxprof/main/dnsmgr.c
    team/murf/mtxprof/main/loader.c
    team/murf/mtxprof/main/pbx.c
    team/murf/mtxprof/main/utils.c
    team/murf/mtxprof/utils/hashtest.c
    team/murf/mtxprof/utils/hashtest2.c
    team/murf/mtxprof/utils/refcounter.c

Modified: team/murf/mtxprof/channels/chan_agent.c
URL: http://svn.digium.com/view/asterisk/team/murf/mtxprof/channels/chan_agent.c?view=diff&rev=127243&r1=127242&r2=127243
==============================================================================
--- team/murf/mtxprof/channels/chan_agent.c (original)
+++ team/murf/mtxprof/channels/chan_agent.c Tue Jul  1 18:09:54 2008
@@ -937,6 +937,7 @@
 static struct ast_channel *agent_new(struct agent_pvt *p, int state)
 {
 	struct ast_channel *tmp;
+	int ret5;
 #if 0
 	if (!p->chan) {
 		ast_log(LOG_WARNING, "No channel? :(\n");
@@ -982,7 +983,9 @@
 	 * implemented in the kernel for this.
 	 */
 	p->app_sleep_cond = 0;
-	if(ast_strlen_zero(p->loginchan) && ast_mutex_trylock(&p->app_lock)) {
+	if (ast_strlen_zero(p->loginchan))
+		ast_mutex_trylock_assign(&p->app_lock, ret5);
+	if(ast_strlen_zero(p->loginchan) && ret5) {
 		if (p->chan) {
 			ast_queue_frame(p->chan, &ast_null_frame);
 			ast_mutex_unlock(&p->lock);	/* For other thread to read the condition. */

Modified: team/murf/mtxprof/channels/chan_dahdi.c
URL: http://svn.digium.com/view/asterisk/team/murf/mtxprof/channels/chan_dahdi.c?view=diff&rev=127243&r1=127242&r2=127243
==============================================================================
--- team/murf/mtxprof/channels/chan_dahdi.c (original)
+++ team/murf/mtxprof/channels/chan_dahdi.c Tue Jul  1 18:09:54 2008
@@ -3612,8 +3612,11 @@
 	if (needlock) {
 		ast_mutex_lock(&master->lock);
 		if (slave) {
-			while (ast_mutex_trylock(&slave->lock)) {
+			int tlock;
+			ast_mutex_trylock_assign(&slave->lock, tlock);
+			while (tlock) {
 				DEADLOCK_AVOIDANCE(&master->lock);
+				ast_mutex_trylock_assign(&slave->lock, tlock);
 			}
 		}
 	}
@@ -3735,6 +3738,7 @@
 	int priority = 0;
 	struct ast_channel *oc0, *oc1;
 	enum ast_bridge_result res;
+	int tlock;
 
 #ifdef PRI_2BCT
 	int triedtopribridge = 0;
@@ -3780,14 +3784,16 @@
 	oc0 = p0->owner;
 	oc1 = p1->owner;
 
-	if (ast_mutex_trylock(&p0->lock)) {
+	ast_mutex_trylock_assign(&p0->lock, tlock);
+	if (tlock) {
 		/* Don't block, due to potential for deadlock */
 		ast_channel_unlock(c0);
 		ast_channel_unlock(c1);
 		ast_log(LOG_NOTICE, "Avoiding deadlock...\n");
 		return AST_BRIDGE_RETRY;
 	}
-	if (ast_mutex_trylock(&p1->lock)) {
+	ast_mutex_trylock_assign(&p1->lock, tlock);
+	if (tlock) {
 		/* Don't block, due to potential for deadlock */
 		ast_mutex_unlock(&p0->lock);
 		ast_channel_unlock(c0);
@@ -5202,9 +5208,12 @@
 	int index;
 	void *readbuf;
 	struct ast_frame *f;
-
-	while (ast_mutex_trylock(&p->lock)) {
+	int tlock;
+	
+	ast_mutex_trylock_assign(&p->lock,tlock);
+	while (tlock) {
 		CHANNEL_DEADLOCK_AVOIDANCE(ast);
+		ast_mutex_trylock_assign(&p->lock,tlock);
 	}
 
 	index = dahdi_get_index(ast, p, 0);

Modified: team/murf/mtxprof/channels/chan_iax2.c
URL: http://svn.digium.com/view/asterisk/team/murf/mtxprof/channels/chan_iax2.c?view=diff&rev=127243&r1=127242&r2=127243
==============================================================================
--- team/murf/mtxprof/channels/chan_iax2.c (original)
+++ team/murf/mtxprof/channels/chan_iax2.c Tue Jul  1 18:09:54 2008
@@ -3816,9 +3816,13 @@
 
 static void lock_both(unsigned short callno0, unsigned short callno1)
 {
+	int tlock;
+	
 	ast_mutex_lock(&iaxsl[callno0]);
-	while (ast_mutex_trylock(&iaxsl[callno1])) {
+	ast_mutex_trylock_assign(&iaxsl[callno1],tlock);
+	while (tlock) {
 		DEADLOCK_AVOIDANCE(&iaxsl[callno0]);
+		ast_mutex_trylock_assign(&iaxsl[callno1],tlock);
 	}
 }
 
@@ -10105,11 +10109,14 @@
 		count = 0;
 		wakeup = -1;
 		AST_LIST_TRAVERSE_SAFE_BEGIN(&frame_queue, f, list) {
+			int tlock;
+			
 			if (f->sentyet)
 				continue;
 			
 			/* Try to lock the pvt, if we can't... don't fret - defer it till later */
-			if (ast_mutex_trylock(&iaxsl[f->callno])) {
+			ast_mutex_trylock_assign(&iaxsl[f->callno],tlock);
+			if (tlock) {
 				wakeup = 1;
 				continue;
 			}
@@ -11346,9 +11353,11 @@
 	char *tmpstr;
 
 	for (x = 0; x < ARRAY_LEN(iaxs); x++) {
+		int tlock;
 		/* Look for an *exact match* call.  Once a call is negotiated, it can only
 		   look up entries for a single context */
-		if (!ast_mutex_trylock(&iaxsl[x])) {
+		ast_mutex_trylock_assign(&iaxsl[x],tlock);
+		if (!tlock) {
 			if (iaxs[x] && !strcasecmp(data, iaxs[x]->dproot))
 				return x;
 			ast_mutex_unlock(&iaxsl[x]);

Modified: team/murf/mtxprof/channels/chan_local.c
URL: http://svn.digium.com/view/asterisk/team/murf/mtxprof/channels/chan_local.c?view=diff&rev=127243&r1=127242&r2=127243
==============================================================================
--- team/murf/mtxprof/channels/chan_local.c (original)
+++ team/murf/mtxprof/channels/chan_local.c Tue Jul  1 18:09:54 2008
@@ -221,11 +221,13 @@
 	/* Ensure that we have both channels locked */
 	ast_channel_trylock_assign(other,lockret);
 	while (other && lockret) {
+		int tlock;
 		ast_mutex_unlock(&p->lock);
 		if (us && us_locked) {
 			do {
 				CHANNEL_DEADLOCK_AVOIDANCE(us);
-			} while (ast_mutex_trylock(&p->lock));
+				ast_mutex_trylock_assign(&p->lock,tlock);
+			} while (tlock);
 		} else {
 			usleep(1);
 			ast_mutex_lock(&p->lock);

Modified: team/murf/mtxprof/channels/chan_mgcp.c
URL: http://svn.digium.com/view/asterisk/team/murf/mtxprof/channels/chan_mgcp.c?view=diff&rev=127243&r1=127242&r2=127243
==============================================================================
--- team/murf/mtxprof/channels/chan_mgcp.c (original)
+++ team/murf/mtxprof/channels/chan_mgcp.c Tue Jul  1 18:09:54 2008
@@ -4359,9 +4359,11 @@
 	struct mgcp_endpoint *e;
 	struct mgcp_gateway *g;
 	int lockret;
+	int tlock;
 	
 	/* Check to see if we're reloading */
-	if (ast_mutex_trylock(&mgcp_reload_lock)) {
+	ast_mutex_trylock_assign(&mgcp_reload_lock,tlock);
+	if (tlock) {
 		ast_log(LOG_WARNING, "MGCP is currently reloading.  Unable to remove module.\n");
 		return -1;
 	} else {

Modified: team/murf/mtxprof/channels/chan_sip.c
URL: http://svn.digium.com/view/asterisk/team/murf/mtxprof/channels/chan_sip.c?view=diff&rev=127243&r1=127242&r2=127243
==============================================================================
--- team/murf/mtxprof/channels/chan_sip.c (original)
+++ team/murf/mtxprof/channels/chan_sip.c Tue Jul  1 18:09:54 2008
@@ -17992,20 +17992,24 @@
 			if (strcmp(p->exten, ast_pickup_ext())) {	/* Call to extension -start pbx on this call */
 				static int pbx_mark = -1;
 				enum ast_pbx_result res;
+#ifdef HAVE_MTX_PROFILE
 				struct timeval start9, end9;
 				static int totaltime = 0;
 				static int numtimes = 0;
 				int timediff;
 				uint64_t st1;
+#endif
 				
 				if (pbx_mark == -1) {
 					pbx_mark = ast_add_profile("pbx_start_time", 0);
 				}
-				
+#ifdef HAVE_MTX_PROFILE
 				ast_log(LOG_NOTICE,"about to start PBX\n");
 				start9 = ast_tvnow();
 				st1 = ast_mark2();
+#endif
 				res = ast_pbx_start(c);
+#ifdef HAVE_MTX_PROFILE
 				ast_mark3(pbx_mark, st1);
 				end9 = ast_tvnow();
 				timediff = ast_tvdiff_us(end9, start9);
@@ -18013,7 +18017,7 @@
 				numtimes++;
 				
 				ast_log(LOG_NOTICE,"PBX is started -- took %d microseconds, avg=%d usec (%d times)\n", timediff, totaltime/numtimes, numtimes);
-
+#endif
 				switch(res) {
 				case AST_PBX_FAILED:
 					ast_log(LOG_WARNING, "Failed to start PBX :(\n");

Modified: team/murf/mtxprof/funcs/func_lock.c
URL: http://svn.digium.com/view/asterisk/team/murf/mtxprof/funcs/func_lock.c?view=diff&rev=127243&r1=127242&r2=127243
==============================================================================
--- team/murf/mtxprof/funcs/func_lock.c (original)
+++ team/murf/mtxprof/funcs/func_lock.c Tue Jul  1 18:09:54 2008
@@ -182,7 +182,9 @@
 	if (count_channel_locks > 1) {
 		struct timeval start = ast_tvnow();
 		for (;;) {
-			if ((res = ast_mutex_trylock(&current->mutex)) == 0)
+			int tlock;
+			ast_mutex_trylock_assign(&current->mutex, tlock)
+			if ((res = tlock) == 0)
 				break;
 			if (ast_tvdiff_ms(ast_tvnow(), start) > 3000)
 				break; /* bail after 3 seconds of waiting */
@@ -190,10 +192,11 @@
 		}
 	} else {
 		/* If the channel doesn't have any locks so far, then there's no possible deadlock. */
-		if (try)
-			res = ast_mutex_trylock(&current->mutex);
-		else
+		if (try) {
+			ast_mutex_trylock_assign(&current->mutex,res);
+		} else {
 			ast_mutex_lock_assign(&current->mutex,res);
+		}
 	}
 
 	if (res == 0) {

Modified: team/murf/mtxprof/include/asterisk.h
URL: http://svn.digium.com/view/asterisk/team/murf/mtxprof/include/asterisk.h?view=diff&rev=127243&r1=127242&r2=127243
==============================================================================
--- team/murf/mtxprof/include/asterisk.h (original)
+++ team/murf/mtxprof/include/asterisk.h Tue Jul  1 18:09:54 2008
@@ -156,6 +156,9 @@
 int64_t ast_mark(int, int start1_stop0);
 uint64_t ast_mark2(void);
 void ast_mark3(int mtx_ind, uint64_t start);
+void ast_mtxprof_bumpbusy(int mtx_ind);
+void ast_mtxprof_busywith(int mtx_ind, int x);
+
 #else /* LOW_MEMORY */
 #define ast_add_profile(a, b) 0
 #define ast_profile(a, b) do { } while (0)

Modified: team/murf/mtxprof/include/asterisk/linkedlists.h
URL: http://svn.digium.com/view/asterisk/team/murf/mtxprof/include/asterisk/linkedlists.h?view=diff&rev=127243&r1=127242&r2=127243
==============================================================================
--- team/murf/mtxprof/include/asterisk/linkedlists.h (original)
+++ team/murf/mtxprof/include/asterisk/linkedlists.h Tue Jul  1 18:09:54 2008
@@ -77,6 +77,8 @@
 */
 #define AST_LIST_TRYLOCK(head)						\
 	ast_mutex_trylock(&(head)->lock) 
+#define AST_LIST_TRYLOCK_ASSIGN(head,var)			\
+	ast_mutex_trylock_assign(&(head)->lock,var) 
 
 /*!
   \brief Write locks a list, without blocking if the list is locked.

Modified: team/murf/mtxprof/include/asterisk/lock.h
URL: http://svn.digium.com/view/asterisk/team/murf/mtxprof/include/asterisk/lock.h?view=diff&rev=127243&r1=127242&r2=127243
==============================================================================
--- team/murf/mtxprof/include/asterisk/lock.h (original)
+++ team/murf/mtxprof/include/asterisk/lock.h Tue Jul  1 18:09:54 2008
@@ -62,17 +62,26 @@
 #define	__MTX_PROF(a, file, func, lineno, start, mtx_prof, lockstr)	return pthread_mutex_lock((a))
 #else
 /* make the MTX_PROF thread-safe (localize the start time, use fetchadd to add in the wait time, and bump the event count) */
-#define	__MTX_PROF(a, file, func, lineno, start, mtx_prof, lockstr)	do {	\
-	int i;					    \
-	if (*(mtx_prof) == -1) {										\
-	    char nbuf[512];												\
+#define	__MTX_PROF(a, file, func, lineno, start, mtx_prof, lockstr)	do {             \
+	int i;					                                                         \
+	if (*(mtx_prof) == -1) {                                                         \
+	    char nbuf[512];												                 \
 		snprintf(nbuf, sizeof(nbuf), "%s__%s__%d__%s", file, func, lineno, lockstr); \
-		*(mtx_prof) = ast_add_profile(nbuf, 0);							\
+		*(mtx_prof) = ast_add_profile(nbuf, 0);							             \
     }						                         \
 	*(start) = ast_mark2();							 \
-	i = pthread_mutex_lock((a));		             \
+	i = pthread_mutex_trylock((a));					 \
+	if (i) {                                         \
+		if (i == EBUSY) {                            \
+			/* record who we are waiting on! */      \
+			ast_mtxprof_bumpbusy(*(mtx_prof));		 \
+		} else {                                     \
+			ast_log(LOG_WARNING,"trying of lock yields %d\n", i);	\
+		}											 \
+		i = pthread_mutex_lock((a));				 \
+	}                                                \
     ast_mark3(*(mtx_prof), *(start));				 \
-	return i;                   \
+	return i;                                        \
 	} while (0)
 #endif	/* HAVE_MTX_PROFILE */
 
@@ -273,7 +282,7 @@
 		if (__res < 0) { /* Shouldn't ever happen, but just in case... */ \
 			ast_channel_lock(chan); \
 		} else { \
-			__ast_pthread_mutex_lock(__filename, __lineno, __func, __mutex_name, &chan->lock_dont_use); \
+			__ast_pthread_mutex_lock(__filename, __lineno, __func, __mutex_name, &chan->lock_dont_use, 0, 0); \
 		} \
 	} while (0)
 
@@ -287,7 +296,7 @@
 		if (__res < 0) { /* Shouldn't ever happen, but just in case... */ \
 			ast_mutex_lock(lock); \
 		} else { \
-			__ast_pthread_mutex_lock(__filename, __lineno, __func, __mutex_name, lock); \
+			__ast_pthread_mutex_lock(__filename, __lineno, __func, __mutex_name, lock, 0, 0); \
 		} \
 	} while (0)
 
@@ -326,7 +335,7 @@
 		if (__res < 0) { /* Shouldn't ever happen, but just in case... */ \
 			ast_mutex_lock(lock); \
 		} else { \
-			__ast_pthread_mutex_lock(__filename, __lineno, __func, __mutex_name, lock); \
+			__ast_pthread_mutex_lock(__filename, __lineno, __func, __mutex_name, lock, 0, 0); \
 		} \
 	} while (0)
 
@@ -473,7 +482,7 @@
 }
 
 static inline int __ast_pthread_mutex_lock(const char *filename, int lineno, const char *func,
-                                           const char* mutex_name, ast_mutex_t *t)
+                                           const char* mutex_name, ast_mutex_t *t, int *mtx_prof, uint64_t *start)
 {
 	int res;
 	struct ast_lock_track *lt = &t->track;
@@ -537,14 +546,34 @@
 			}
 		} while (res == EBUSY);
 	}
-#else
+#else /* NOT DETECT DEADLOCKS below */
 #ifdef	HAVE_MTX_PROFILE
-	/* detecting deadlocks will turn off MTX_PROFILE for the time being */
 	/* why? because mtx_prof is per-lock, and we need to pass it into
        this func; then we need to add its local decl to whereever this
        func is called from. Will check it out later */
-#endif
-	res = pthread_mutex_lock(&t->mutex);
+	do {
+		if (*(mtx_prof) == -1) {
+			char nbuf[512];
+			snprintf(nbuf, sizeof(nbuf), "%s__%s__%d__%s", file, func, lineno, lockstr);
+			*(mtx_prof) = ast_add_profile(nbuf, 0);
+		}
+		*(start) = ast_mark2();
+		res = pthread_mutex_trylock(&t->mutex);
+		if (i) {
+			if (i == EBUSY) {
+				/* record who we are waiting on! */
+				ast_mtxprof_bumpbusy(*(mtx_prof));
+			} else {
+				ast_log(LOG_WARNING,"trying of lock yields %d\n", i);
+			}
+			res = pthread_mutex_lock(&t->mutex);
+		}
+		ast_mark3(*(mtx_prof), *(start));
+		return i;
+	} while (0)
+#else /* NOT DETECT_DEADLOCKS and NOT HAVE_MTX_PROFILE */
+		res = pthread_mutex_lock(&t->mutex);
+#endif /* HAVE_MTX_PROFILE */
 #endif /* DETECT_DEADLOCKS */
 
 	if (!res) {
@@ -938,12 +967,19 @@
 
 	return res;
 }
-
+#ifdef HAVE_MTX_PROFILE
+#define ast_mutex_lock(a)			do {uint64_t start; static int mutprof=-1; __ast_pthread_mutex_lock(__FILE__, __LINE__, __PRETTY_FUNCTION__, #a, a, &mutprof, &start);} while(0)
+#define ast_mutex_lock_assign(a,retval) do {uint64_t start; static int mutprof=-1; retval = __ast_pthread_mutex_lock(__FILE__, __LINE__, __PRETTY_FUNCTION__, #a, a, &mutprof, &start);} while(0)
+#define ast_mutex_trylock(a)			do {uint64_t start; static int mutprof=-1; __ast_pthread_mutex_trylock(__FILE__, __LINE__, __PRETTY_FUNCTION__, #a, a, &mutprof, &start);} while(0)
+#define ast_mutex_trylock_assign(a,retval)			{uint64_t start; static int mutprof=-1; retval=__ast_pthread_mutex_trylock(__FILE__, __LINE__, __PRETTY_FUNCTION__, #a, a, &mutprof, &start);} while(0)
+#else
+#define ast_mutex_lock(a)			__ast_pthread_mutex_lock(__FILE__, __LINE__, __PRETTY_FUNCTION__, #a, a, 0, 0)
+#define ast_mutex_lock_assign(a,retval) retval = __ast_pthread_mutex_lock(__FILE__, __LINE__, __PRETTY_FUNCTION__, #a, a, 0, 0)
+#define ast_mutex_trylock(a)			__ast_pthread_mutex_trylock(__FILE__, __LINE__, __PRETTY_FUNCTION__, #a, a)
+#define ast_mutex_trylock_assign(a,retval)			retval=__ast_pthread_mutex_trylock(__FILE__, __LINE__, __PRETTY_FUNCTION__, #a, a)
+#endif
 #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_lock_assign(a,retval) retval = __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)
-#define ast_mutex_trylock(a)			__ast_pthread_mutex_trylock(__FILE__, __LINE__, __PRETTY_FUNCTION__, #a, a)
 #define ast_cond_init(cond, attr)		__ast_cond_init(__FILE__, __LINE__, __PRETTY_FUNCTION__, #cond, cond, attr)
 #define ast_cond_destroy(cond)			__ast_cond_destroy(__FILE__, __LINE__, __PRETTY_FUNCTION__, #cond, cond)
 #define ast_cond_signal(cond)			__ast_cond_signal(__FILE__, __LINE__, __PRETTY_FUNCTION__, #cond, cond)
@@ -1510,17 +1546,62 @@
 {
 	return pthread_mutex_destroy(pmutex);
 }
-#define ast_mutex_lock(x) {int start; static int mutprof=-1; ast_mutex_lock2((x), __FILE__, __FUNCTION__,  __LINE__, &start, &mutprof, #x);}
-#define ast_mutex_lock_assign(x,retval) {int start; static int mutprof=-1; retval = ast_mutex_lock2((x), __FILE__, __FUNCTION__,  __LINE__, &start, &mutprof, #x);}
+#define ast_mutex_lock(x) {uint64_t start; static int mutprof=-1; ast_mutex_lock2((x), __FILE__, __FUNCTION__,  __LINE__, &start, &mutprof, #x);}
+#define ast_mutex_lock_assign(x,retval) {uint64_t start; static int mutprof=-1; retval = ast_mutex_lock2((x), __FILE__, __FUNCTION__,  __LINE__, &start, &mutprof, #x);}
+#define ast_mutex_trylock(x) {uint64_t start; static int mutprof=-1; ast_mutex_trylock2((x), __FILE__, __FUNCTION__,  __LINE__, &start, &mutprof, #x);}
+#define ast_mutex_trylock_assign(x,retval) {uint64_t start; static int mutprof=-1; retval = ast_mutex_trylock2((x), __FILE__, __FUNCTION__,  __LINE__, &start, &mutprof, #x);}
 	
-static inline int ast_mutex_lock2(ast_mutex_t *pmutex, char *file, const char *func, int lineno, int *start, int *mutprof, char *lockstr)
-{
-	__MTX_PROF(pmutex, file, func, lineno, start, mutprof, lockstr);
-}
-
-static inline int ast_mutex_trylock(ast_mutex_t *pmutex)
-{
+static inline int ast_mutex_lock2(ast_mutex_t *pmutex, char *file, const char *func, int lineno, uint64_t *start, int *mtx_prof, char *lockstr)
+{
+#ifdef	HAVE_MTX_PROFILE
+	int i;
+	if (*(mtx_prof) == -1) {
+	    char nbuf[512];
+		snprintf(nbuf, sizeof(nbuf), "%s__%s__%d__%s", file, func, lineno, lockstr);
+		*(mtx_prof) = ast_add_profile(nbuf, 0);
+    }
+	*(start) = ast_mark2();
+	i = pthread_mutex_trylock(pmutex);
+	if (i) {
+		if (i == EBUSY) {
+			/* record who we are waiting on! */
+			ast_mtxprof_bumpbusy(*(mtx_prof));
+		} else {
+			ast_log(LOG_WARNING,"trying of lock yields %d\n", i);
+		}
+		i = pthread_mutex_lock(pmutex);
+	}
+    ast_mark3(*(mtx_prof), *(start));
+	return i;
+#else
+	return pthread_mutex_lock(pmutex);
+#endif
+}
+
+static inline int ast_mutex_trylock2(ast_mutex_t *pmutex, char *file, const char *func, int lineno, uint64_t *start, int *mutprof, char *lockstr)
+{
+#ifdef	HAVE_MTX_PROFILE
+	int i;
+	if (*(mutprof) == -1) {
+	    char nbuf[512];
+		snprintf(nbuf, sizeof(nbuf), "%s__%s__%d__%s", file, func, lineno, lockstr);
+		*(mutprof) = ast_add_profile(nbuf, 0);
+    }
+	*(start) = ast_mark2();
+	i = pthread_mutex_trylock(pmutex);
+	if (i) {
+		if (i == EBUSY) {
+			/* record who we are waiting on! */
+			ast_mtxprof_bumpbusy(*(mutprof));
+		} else {
+			ast_log(LOG_WARNING,"trying of lock yields %d\n", i);
+		}
+	}
+    ast_mark3(*(mutprof), *(start));
+	return i;
+#else
 	return pthread_mutex_trylock(pmutex);
+#endif
 }
 
 typedef pthread_cond_t ast_cond_t;
@@ -1783,6 +1864,7 @@
 #ifndef DEBUG_CHANNEL_LOCKS
 /*! \brief Lock a channel. If DEBUG_CHANNEL_LOCKS is defined 
 	in the Makefile, print relevant output for debugging */
+#ifdef HAVE_MTX_PROFILE
 #define ast_channel_lock(x)		ast_log(LOG_NOTICE,"LockChan %s\n", x->name); ast_mutex_lock(&x->lock_dont_use); \
 	ast_log(LOG_NOTICE,"LockChan %s OBTAINED\n", x->name);
 /*! \brief Unlock a channel. If DEBUG_CHANNEL_LOCKS is defined 
@@ -1792,8 +1874,19 @@
 /*! \brief Try locking a channel. If DEBUG_CHANNEL_LOCKS is defined 
 	in the Makefile, print relevant output for debugging */
 #define ast_channel_trylock(x)		if(!ast_mutex_trylock(&x->lock_dont_use))ast_log(LOG_NOTICE,"TryLockChan for %s success\n", x->name)
-#define ast_channel_trylock_assign(x, var)		var = ast_mutex_trylock(&x->lock_dont_use);	\
+#define ast_channel_trylock_assign(x, var)		ast_mutex_trylock_assign(&x->lock_dont_use,(var)); \
 	if(!var)ast_log(LOG_NOTICE,"TryChan %s success\n", x->name); 
+#else
+#define ast_channel_lock(x)		ast_mutex_lock(&x->lock_dont_use);
+/*! \brief Unlock a channel. If DEBUG_CHANNEL_LOCKS is defined 
+	in the Makefile, print relevant output for debugging */
+#define ast_channel_unlock(x)		ast_mutex_unlock(&x->lock_dont_use)
+#define ast_channel_unlock_comma(x)		ast_mutex_unlock(&x->lock_dont_use)
+/*! \brief Try locking a channel. If DEBUG_CHANNEL_LOCKS is defined 
+	in the Makefile, print relevant output for debugging */
+#define ast_channel_trylock(x)		ast_mutex_trylock(&x->lock_dont_use)
+#define ast_channel_trylock_assign(x, var)		ast_mutex_trylock_assign(&x->lock_dont_use, var)
+#endif
 #else
 
 #define ast_channel_lock(a) __ast_channel_lock(a, __FILE__, __LINE__, __PRETTY_FUNCTION__)

Modified: team/murf/mtxprof/main/asterisk.c
URL: http://svn.digium.com/view/asterisk/team/murf/mtxprof/main/asterisk.c?view=diff&rev=127243&r1=127242&r2=127243
==============================================================================
--- team/murf/mtxprof/main/asterisk.c (original)
+++ team/murf/mtxprof/main/asterisk.c Tue Jul  1 18:09:54 2008
@@ -521,6 +521,7 @@
 	int64_t	mark;
 	int	value;
 	int	events;
+	int busycount;
 };
 
 struct profile_data {
@@ -543,7 +544,6 @@
 		prof_data = ast_calloc(1, l + n*sizeof(struct profile_entry));
 		if (prof_data == NULL)
 			return -1;
-		prof_data->entries = 0;
 		prof_data->max_size = n;
 	}
 	if (prof_data->entries >= prof_data->max_size) {
@@ -559,6 +559,7 @@
 	prof_data->e[n].name = ast_strdup(name);
 	prof_data->e[n].value = 0;
 	prof_data->e[n].events = 0;
+	prof_data->e[n].busycount = 0;
 	prof_data->e[n].mark = 0;
 	prof_data->e[n].scale = scale;
 	return n;
@@ -627,6 +628,15 @@
 		time9 /= prof_data->e[mtx_ind].scale;
 	ast_atomic_fetchadd_int(&prof_data->e[mtx_ind].value, time9);
 	ast_atomic_fetchadd_int(&prof_data->e[mtx_ind].events, 1);
+}
+
+void ast_mtxprof_bumpbusy(int mtx_ind)
+{
+	ast_atomic_fetchadd_int(&prof_data->e[mtx_ind].busycount, 1);
+}
+
+void ast_mtxprof_busywith(int mtx_ind, int x)
+{
 }
 
 #define DEFINE_PROFILE_MIN_MAX_VALUES min = 0; \
@@ -662,15 +672,15 @@
 	DEFINE_PROFILE_MIN_MAX_VALUES;
 	ast_cli(a->fd, "profile values (%d, allocated %d)\n-------------------\n",
 		prof_data->entries, prof_data->max_size);
-	ast_cli(a->fd, "%6s   %8s  %10s %12s %12s  %s\n", "ID", "Scale", "Events",
+	ast_cli(a->fd, "%6s   %8s  %10s %10s %12s %12s  %s\n", "ID", "Scale", "Events", "BusyCnt",
 			"Value", "Average", "Name");
 	for (i = min; i < max; i++) {
 		struct profile_entry *e = &prof_data->e[i];
 		if (!search || strstr(prof_data->e[i].name, search))
-		    ast_cli(a->fd, "%6d: [%8ld] %10ld %12lld %12lld  %s\n",
+		    ast_cli(a->fd, "%6d: [%8ld] %10ld %10ld %12lld %12lld  %s\n",
 			i,
 			(long)e->scale,
-			(long)e->events, (long long)e->value,
+			(long)e->events, (long)e->busycount, (long long)e->value,
 			(long long)(e->events ? e->value / e->events : e->value),
 			e->name);
 	}

Modified: team/murf/mtxprof/main/astobj2.c
URL: http://svn.digium.com/view/asterisk/team/murf/mtxprof/main/astobj2.c?view=diff&rev=127243&r1=127242&r2=127243
==============================================================================
--- team/murf/mtxprof/main/astobj2.c (original)
+++ team/murf/mtxprof/main/astobj2.c Tue Jul  1 18:09:54 2008
@@ -176,7 +176,7 @@
 	
 	if (p == NULL)
 		return -1;
-	ret =  ast_mutex_trylock(&p->priv_data.lock);
+	ast_mutex_trylock_assign(&p->priv_data.lock, ret);
 #ifdef AO2_DEBUG
 	if (!ret)
 		ast_atomic_fetchadd_int(&ao2.total_locked, 1);

Modified: team/murf/mtxprof/main/channel.c
URL: http://svn.digium.com/view/asterisk/team/murf/mtxprof/main/channel.c?view=diff&rev=127243&r1=127242&r2=127243
==============================================================================
--- team/murf/mtxprof/main/channel.c (original)
+++ team/murf/mtxprof/main/channel.c Tue Jul  1 18:09:54 2008
@@ -1165,11 +1165,13 @@
 		done = c == NULL || lockret == 0;
 		if (!done) {
 			ast_debug(1, "Avoiding %s for channel '%p'\n", msg, c);
-			if (retries == 19) {
+			if (retries == 199) {
 				/* We are about to fail due to a deadlock, so report this
 				 * while we still have the list lock.
 				 */
+#ifdef HAVE_MTX_PROFILE
 				ast_log(LOG_NOTICE, "Failure, could not lock '%p' after %d retries!\n", c, retries);
+#endif
 				ast_debug(1, "Failure, could not lock '%p' after %d retries!\n", c, retries);
 				/* As we have deadlocked, we will skip this channel and
 				 * see if there is another match.

Modified: team/murf/mtxprof/main/dnsmgr.c
URL: http://svn.digium.com/view/asterisk/team/murf/mtxprof/main/dnsmgr.c?view=diff&rev=127243&r1=127242&r2=127243
==============================================================================
--- team/murf/mtxprof/main/dnsmgr.c (original)
+++ team/murf/mtxprof/main/dnsmgr.c Tue Jul  1 18:09:54 2008
@@ -216,9 +216,11 @@
 {
 	struct refresh_info *info = (struct refresh_info *)data;
 	struct ast_dnsmgr_entry *entry;
-
+	int tlock;
+	
 	/* if a refresh or reload is already in progress, exit now */
-	if (ast_mutex_trylock(&refresh_lock)) {
+	ast_mutex_trylock_assign(&refresh_lock,tlock);
+	if (tlock) {
 		if (info->verbose)
 			ast_log(LOG_WARNING, "DNS Manager refresh already in progress.\n");
 		return -1;

Modified: team/murf/mtxprof/main/loader.c
URL: http://svn.digium.com/view/asterisk/team/murf/mtxprof/main/loader.c?view=diff&rev=127243&r1=127242&r2=127243
==============================================================================
--- team/murf/mtxprof/main/loader.c (original)
+++ team/murf/mtxprof/main/loader.c Tue Jul  1 18:09:54 2008
@@ -567,8 +567,10 @@
 	struct ast_module *cur;
 	int res = 0; /* return value. 0 = not found, others, see below */
 	int i;
-
-	if (ast_mutex_trylock(&reloadlock)) {
+	int tlock;
+	
+	ast_mutex_trylock_assign(&reloadlock,tlock);
+	if (tlock) {
 		ast_verbose("The previous reload command didn't finish yet\n");
 		return -1;	/* reload already in progress */
 	}
@@ -974,8 +976,10 @@
 	struct ast_module *cur;
 	int unlock = -1;
 	int total_mod_loaded = 0;
-
-	if (AST_LIST_TRYLOCK(&module_list))
+	int tlock;
+
+	AST_LIST_TRYLOCK_ASSIGN(&module_list,tlock);
+	if (tlock)
 		unlock = 0;
  
 	AST_LIST_TRAVERSE(&module_list, cur, entry) {

Modified: team/murf/mtxprof/main/pbx.c
URL: http://svn.digium.com/view/asterisk/team/murf/mtxprof/main/pbx.c?view=diff&rev=127243&r1=127242&r2=127243
==============================================================================
--- team/murf/mtxprof/main/pbx.c (original)
+++ team/murf/mtxprof/main/pbx.c Tue Jul  1 18:09:54 2008
@@ -3810,6 +3810,7 @@
 enum ast_pbx_result ast_pbx_start(struct ast_channel *c)
 {
 	pthread_t t;
+#ifdef HAVE_MTX_PROFILE
 	struct timeval start9 = ast_tvnow(), end9;
 	static int totaltime = 0;
 	static int numtimes = 0;
@@ -3818,7 +3819,7 @@
 	static int totaltime2 = 0;
 	static int numtimes2 = 0;
 	int timediff2;
-
+#endif
 	if (!c) {
 		ast_log(LOG_WARNING, "Asked to start thread on NULL channel?\n");
 		return AST_PBX_FAILED;
@@ -3827,6 +3828,7 @@
 	if (increase_call_count(c))
 		return AST_PBX_CALL_LIMIT;
 
+#ifdef HAVE_MTX_PROFILE
 	end9 = ast_tvnow();
 	timediff = ast_tvdiff_us(end9, start9);
 	totaltime += timediff;
@@ -3838,6 +3840,7 @@
 	totaltime2 += timediff2;
 	numtimes2++;
 	ast_log(LOG_NOTICE,"ast_log took %d microseconds, avg=%d usec (%d times)\n", timediff2, totaltime2/numtimes2, numtimes2);
+#endif
 	/* Start a new thread, and get something handling this channel. */
 	if (ast_pthread_create_detached(&t, NULL, pbx_thread, c)) {
 		ast_log(LOG_WARNING, "Failed to create new channel thread\n");

Modified: team/murf/mtxprof/main/utils.c
URL: http://svn.digium.com/view/asterisk/team/murf/mtxprof/main/utils.c?view=diff&rev=127243&r1=127242&r2=127243
==============================================================================
--- team/murf/mtxprof/main/utils.c (original)
+++ team/murf/mtxprof/main/utils.c Tue Jul  1 18:09:54 2008
@@ -1041,10 +1041,14 @@
 			     void *data, size_t stacksize, const char *file, const char *caller,
 			     int line, const char *start_fn)
 {
+#ifdef HAVE_MTX_PROFILE
 	struct timeval start9, end9;
 	static int totaltime = 0;
 	static int numtimes = 0;
-	int timediff, ret7;
+	int timediff;
+#endif
+	int ret7;
+
 	
 #if !defined(LOW_MEMORY)
 	struct thr_arg *a;
@@ -1093,14 +1097,18 @@
 	}
 #endif
 
+#ifdef HAVE_MTX_PROFILE
 	start9 = ast_tvnow();
+#endif
 	ret7 =  pthread_create(thread, attr, start_routine, data); /* We're in ast_pthread_create, so it's okay */
+#ifdef HAVE_MTX_PROFILE
 	end9 = ast_tvnow();
 	timediff = ast_tvdiff_us(end9, start9);
 	totaltime += timediff;
 	numtimes++;
 	
 	ast_log(LOG_NOTICE,"pthread_create took %d microseconds, avg=%d usec (%d times)\n", timediff, totaltime/numtimes, numtimes);
+#endif
 
 	return ret7;
 }

Modified: team/murf/mtxprof/utils/hashtest.c
URL: http://svn.digium.com/view/asterisk/team/murf/mtxprof/utils/hashtest.c?view=diff&rev=127243&r1=127242&r2=127243
==============================================================================
--- team/murf/mtxprof/utils/hashtest.c (original)
+++ team/murf/mtxprof/utils/hashtest.c Tue Jul  1 18:09:54 2008
@@ -50,6 +50,7 @@
 }
 uint64_t ast_mark2(void){ return 0;}
 void ast_mark3(int mtx_ind, uint64_t start) {}
+void ast_mtxprof_bumpbusy(int mtx_ind){}
 
 #endif
 

Modified: team/murf/mtxprof/utils/hashtest2.c
URL: http://svn.digium.com/view/asterisk/team/murf/mtxprof/utils/hashtest2.c?view=diff&rev=127243&r1=127242&r2=127243
==============================================================================
--- team/murf/mtxprof/utils/hashtest2.c (original)
+++ team/murf/mtxprof/utils/hashtest2.c Tue Jul  1 18:09:54 2008
@@ -52,7 +52,7 @@
 }
 uint64_t ast_mark2(void){ return 0;}
 void ast_mark3(int mtx_ind, uint64_t start) {}
-
+void ast_mtxprof_bumpbusy(int mtx_ind) {}
 #endif
 
 /* my OBJECT */

Modified: team/murf/mtxprof/utils/refcounter.c
URL: http://svn.digium.com/view/asterisk/team/murf/mtxprof/utils/refcounter.c?view=diff&rev=127243&r1=127242&r2=127243
==============================================================================
--- team/murf/mtxprof/utils/refcounter.c (original)
+++ team/murf/mtxprof/utils/refcounter.c Tue Jul  1 18:09:54 2008
@@ -239,6 +239,7 @@
 }
 uint64_t ast_mark2(void){ return 0;}
 void ast_mark3(int mtx_ind, uint64_t start) {}
+void ast_mtxprof_bumpbusy(int mtx_ind) {}
 
 #endif
 




More information about the asterisk-commits mailing list