Index: channel.c
===================================================================
RCS file: /usr/cvsroot/asterisk/channel.c,v
retrieving revision 1.240
diff -u -r1.240 channel.c
--- channel.c	1 Sep 2005 22:28:33 -0000	1.240
+++ channel.c	5 Sep 2005 14:32:54 -0000
@@ -3506,3 +3506,128 @@
 	for (cur = vars; cur; cur = cur->next)
 		pbx_builtin_setvar_helper(chan, cur->name, cur->value);	
 }
+
+
+/*--- ast_channel_unlock: Unlock AST channel (and print debugging output) */
+/*	Return values as ast_mutex_unlock (pthread_mutex_unlock) */
+int ast_channel_unlock(struct ast_channel *chan)
+{
+	int res = 0;
+	if (!chan) {
+		ast_log(LOG_DEBUG, "::::==== Unlocking non-existing channel \n");
+		return -1;
+	} else if (option_debug > 3) {
+		ast_log(LOG_DEBUG, "::::==== Unlocking AST channel %s\n", chan->name);
+	}
+		
+	res = ast_mutex_unlock(&chan->lock);
+	
+	if (option_debug > 3) {
+#ifdef __linux__
+		int count = 0;
+#ifdef DEBUG_THREADS
+		if ((count = chan->lock.mutex.__m_count))
+#else
+		if ((count = chan->lock.__m_count))
+#endif
+			ast_log(LOG_DEBUG, ":::=== Still have %d locks (recursive)\n", count);
+#endif
+		if (!res)
+			ast_log(LOG_DEBUG, "::::==== Channel %s was unlocked\n", chan->name);
+		if (res == EINVAL) {
+			ast_log(LOG_DEBUG, "::::==== Channel %s had no lock by this thread. Failed unlocking\n", chan->name);
+		}
+	}
+
+	if (res == EPERM) {
+		/* We had no lock, so okey any way*/
+		if (option_debug > 3)
+			ast_log(LOG_DEBUG, "::::==== Channel %s was not locked at all \n", chan->name);
+		res = 0;
+	}
+
+	return res;
+}
+
+/*--- ast_channel_lock: Lock AST channel (and print debugging output) */
+/*	Return values as ast_mutex_lock (pthread_mutex_lock) */
+int ast_channel_lock(struct ast_channel *chan)
+{
+	int res;
+
+	if (!chan) {
+		ast_log(LOG_ERROR, "Locking non-existing channel \n");
+		return -1;
+	} else if (option_debug > 3)
+		ast_log(LOG_DEBUG, "====:::: Locking AST channel %s\n", chan->name);
+
+	res = ast_mutex_lock(&chan->lock);
+
+	if (option_debug > 3) {
+#ifdef __linux__
+		int count = 0;
+#ifdef DEBUG_THREADS
+		if ((count = chan->lock.mutex.__m_count))
+#else
+		if ((count = chan->lock.__m_count))
+#endif
+			ast_log(LOG_DEBUG, ":::=== Now have %d locks (recursive)\n", count);
+#endif
+		if (!res)
+			ast_log(LOG_DEBUG, "::::==== Channel %s was locked\n", chan->name);
+		if (res == EDEADLK) {
+			/* We had no lock, so okey any way */
+			if (option_debug > 3)
+				ast_log(LOG_DEBUG, "::::==== Channel %s was not locked by us. Lock would cause deadlock.\n", chan->name);
+		}
+		if (res == EINVAL) {
+			if (option_debug > 3)
+				ast_log(LOG_DEBUG, "::::==== Channel %s lock failed. No mutex.\n", chan->name);
+		}
+	}
+	
+	return res;
+}
+
+/*--- ast_channel_trylock: Try locking AST channel (and print debugging output) */
+/*	Return values as ast_mutex_trylock (pthread_mutex_trylock) */
+int ast_channel_trylock(struct ast_channel *chan)
+{
+	int res;
+
+	if (!chan) {
+		ast_log(LOG_ERROR, "Locking non-existing channel \n");
+		return -1;
+	} else if (option_debug > 3)
+		ast_log(LOG_DEBUG, "====:::: Trying to lock AST channel %s\n", chan->name);
+	res = ast_mutex_trylock(&chan->lock);
+	if (option_debug > 3) {
+#ifdef __linux__
+		int count = 0;
+#ifdef DEBUG_THREADS
+		if ((count = chan->lock.mutex.__m_count))
+#else
+		if ((count = chan->lock.__m_count))
+#endif
+			ast_log(LOG_DEBUG, ":::=== Now have %d locks (recursive)\n", count);
+#endif
+		if (!res)
+			ast_log(LOG_DEBUG, "::::==== Channel %s was locked\n", chan->name);
+		if (res == EBUSY) {
+			/* We failed to lock */
+			if (option_debug > 3)
+				ast_log(LOG_DEBUG, "::::==== Channel %s failed to lock. Not waiting around...\n", chan->name);
+		}
+		if (res == EDEADLK) {
+			/* We had no lock, so okey any way*/
+			if (option_debug > 3)
+				ast_log(LOG_DEBUG, "::::==== Channel %s was not locked. Lock would cause deadlock.\n", chan->name);
+		}
+		if (res == EINVAL) {
+			if (option_debug > 3)
+				ast_log(LOG_DEBUG, "::::==== Channel %s lock failed. No mutex.\n", chan->name);
+		}
+	}
+	
+	return res;
+}
Index: include/asterisk/channel.h
===================================================================
RCS file: /usr/cvsroot/asterisk/include/asterisk/channel.h,v
retrieving revision 1.99
diff -u -r1.99 channel.h
--- include/asterisk/channel.h	1 Sep 2005 00:10:49 -0000	1.99
+++ include/asterisk/channel.h	5 Sep 2005 14:32:54 -0000
@@ -1090,4 +1093,20 @@
 }
 #endif
 
+/*! \brief Embed channel locking in a routine with debugging output 
+	Return values are the same ast ast_mutex_lock (pthread_mutex_lock)
+	\param chan	Channel to lock */
+int ast_channel_lock(struct ast_channel *chan);
+
+/*! \brief Embed channel unlocking in a routine with debugging output 
+	Return values are the same ast ast_mutex_unlock (pthread_mutex_unlock)
+	\param chan	Channel to unlock */
+int ast_channel_unlock(struct ast_channel *chan);
+
+/*! \brief Embed channel trylocking in a routine with debugging output 
+	Return values are the same ast ast_mutex_trylock (pthread_mutex_trylock)
+	\param chan	Channel to unlock */
+int ast_channel_trylock(struct ast_channel *chan);
+
+
 #endif /* _ASTERISK_CHANNEL_H */
Index: channels/chan_sip.c
===================================================================
RCS file: /usr/cvsroot/asterisk/channels/chan_sip.c,v
retrieving revision 1.836
diff -u -r1.836 chan_sip.c
--- channels/chan_sip.c	2 Sep 2005 19:24:32 -0000	1.836
+++ channels/chan_sip.c	5 Sep 2005 14:32:56 -0000
@@ -1083,7 +1083,7 @@
 	char iabuf[INET_ADDRSTRLEN];
 	int reschedule = DEFAULT_RETRANS;
 
-	/* Lock channel */
+	/* Lock SIP pvt */
 	ast_mutex_lock(&pkt->owner->lock);
 
 	if (pkt->retrans < MAX_RETRANS) {
@@ -1140,7 +1140,7 @@
 	pkt->retransid = -1;
 
 	if (ast_test_flag(pkt, FLAG_FATAL)) {
-		while(pkt->owner->owner && ast_mutex_trylock(&pkt->owner->owner->lock)) {
+		while(pkt->owner->owner && ast_channel_trylock(pkt->owner->owner)) {
 			ast_mutex_unlock(&pkt->owner->lock);
 			usleep(1);
 			ast_mutex_lock(&pkt->owner->lock);
@@ -1149,7 +1149,7 @@
 			ast_set_flag(pkt->owner, SIP_ALREADYGONE);
 			ast_log(LOG_WARNING, "Hanging up call %s - no reply to our critical packet.\n", pkt->owner->callid);
 			ast_queue_hangup(pkt->owner->owner);
-			ast_mutex_unlock(&pkt->owner->owner->lock);
+			ast_channel_unlock(pkt->owner->owner);
 		} else {
 			/* If no channel owner, destroy now */
 			ast_set_flag(pkt->owner, SIP_NEEDDESTROY);	
@@ -1901,10 +1901,10 @@
 	ast_mutex_lock(&p->lock);
 	p->initid = -1;
 	if (p->owner) {
-		if (!ast_mutex_trylock(&p->owner->lock)) {
+		if (!ast_channel_trylock(p->owner)) {
 			ast_log(LOG_NOTICE, "Auto-congesting %s\n", p->owner->name);
 			ast_queue_control(p->owner, AST_CONTROL_CONGESTION);
-			ast_mutex_unlock(&p->owner->lock);
+			ast_channel_unlock(p->owner);
 		}
 	}
 	ast_mutex_unlock(&p->lock);
@@ -2048,11 +2048,11 @@
 	/* Unlink us from the owner if we have one */
 	if (p->owner) {
 		if (lockowner)
-			ast_mutex_lock(&p->owner->lock);
+			ast_channel_lock(p->owner);
 		ast_log(LOG_DEBUG, "Detaching from %s\n", p->owner->name);
 		p->owner->tech_pvt = NULL;
 		if (lockowner)
-			ast_mutex_unlock(&p->owner->lock);
+			ast_channel_unlock(p->owner);
 	}
 	/* Clear history */
 	while(p->history) {
@@ -6149,7 +6149,7 @@
 			/* Go ahead and lock it (and its owner) before returning */
 			ast_mutex_lock(&sip_pvt_ptr->lock);
 			if (sip_pvt_ptr->owner) {
-				while(ast_mutex_trylock(&sip_pvt_ptr->owner->lock)) {
+				while(ast_channel_trylock(sip_pvt_ptr->owner)) {
 					ast_mutex_unlock(&sip_pvt_ptr->lock);
 					usleep(1);
 					ast_mutex_lock(&sip_pvt_ptr->lock);
@@ -8628,30 +8628,34 @@
 		return NULL;
 	}
 
-	ast_mutex_lock(&chan->lock);
+	ast_channel_lock(chan);
+
 	if (chan->type != channeltype) {
 		ast_log(LOG_WARNING, "This function can only be used on SIP channels.\n");
-		ast_mutex_unlock(&chan->lock);
+		ast_channel_unlock(chan);
 		return NULL;
 	}
 
+
 	p = chan->tech_pvt;
 
 	/* If there is no private structure, this channel is no longer alive */
 	if (!p) {
-		ast_mutex_unlock(&chan->lock);
+		ast_log(LOG_WARNING, "This channel is not active any more.");
+		ast_channel_unlock(chan);
 		return NULL;
 	}
 
+
 	content = get_header(&p->initreq, data);
 
 	if (ast_strlen_zero(content)) {
-		ast_mutex_unlock(&chan->lock);
+		ast_channel_unlock(chan);
 		return NULL;
 	}
 
 	ast_copy_string(buf, content, len);
-	ast_mutex_unlock(&chan->lock);
+	ast_channel_unlock(chan);
 
 	return buf;
 }
@@ -8775,10 +8779,10 @@
 		return NULL;
 	}
 
-	ast_mutex_lock(&chan->lock);
+	ast_channel_lock(chan);
 	if (chan->type != channeltype) {
 		ast_log(LOG_WARNING, "This function can only be used on SIP channels.\n");
-		ast_mutex_unlock(&chan->lock);
+		ast_channel_unlock(chan);
 		return NULL;
 	}
 
@@ -8787,7 +8791,7 @@
 
 	/* If there is no private structure, this channel is no longer alive */
 	if (!p) {
-		ast_mutex_unlock(&chan->lock);
+		ast_channel_unlock(chan);
 		return NULL;
 	}
 
@@ -8807,7 +8811,7 @@
 		ast_mutex_unlock(&chan->lock);
 		return NULL;
 	}
-	ast_mutex_unlock(&chan->lock);
+	ast_channel_unlock(chan);
 
 	return buf;
 }
@@ -9378,9 +9382,9 @@
 	chan2 = d->chan2;
 	copy_request(&req, &d->req);
 	free(d);
-	ast_mutex_lock(&chan1->lock);
+	ast_channel_lock(chan1);
 	ast_do_masquerade(chan1);
-	ast_mutex_unlock(&chan1->lock);
+	ast_channel_unlock(chan1);
 	res = ast_park_call(chan1, chan2, 0, &ext);
 	/* Then hangup */
 	ast_hangup(chan2);
@@ -9424,14 +9428,14 @@
 	ast_copy_string(chan2m->context, chan2->context, sizeof(chan2m->context));
 	ast_copy_string(chan2m->exten, chan2->exten, sizeof(chan2m->exten));
 	chan2m->priority = chan2->priority;
-	ast_mutex_lock(&chan2m->lock);
+	ast_channel_lock(chan2m);
 	if (ast_do_masquerade(chan2m)) {
 		ast_log(LOG_WARNING, "Masquerade failed :(\n");
-		ast_mutex_unlock(&chan2m->lock);
+		ast_channel_unlock(chan2m);
 		ast_hangup(chan2m);
 		return -1;
 	}
-	ast_mutex_unlock(&chan2m->lock);
+	ast_channel_unlock(chan2m);
 	d = malloc(sizeof(struct sip_dual));
 	if (d) {
 		memset(d, 0, sizeof(*d));
@@ -9695,7 +9699,7 @@
 			build_route(p, req, 0);
 			if (c) {
 				/* Pre-lock the call */
-				ast_mutex_lock(&c->lock);
+				ast_channel_lock(c);
 			}
 		}
 		
@@ -9715,7 +9719,7 @@
 				if (ast_pbx_start(c)) {
 					ast_log(LOG_WARNING, "Failed to start PBX :(\n");
 					/* Unlock locks so ast_hangup can do its magic */
-					ast_mutex_unlock(&c->lock);
+					ast_channel_unlock(c);
 					ast_mutex_unlock(&p->lock);
 					ast_hangup(c);
 					ast_mutex_lock(&p->lock);
@@ -9726,7 +9730,7 @@
 					c = NULL;
 				}
 			} else {
-				ast_mutex_unlock(&c->lock);
+				ast_channel_unlock(c);
 				if (ast_pickup_call(c)) {
 					ast_log(LOG_NOTICE, "Nothing to pick up\n");
 					if (ignore)
@@ -9805,7 +9809,7 @@
 				ast_log(LOG_DEBUG,"202 Accepted (supervised)\n");
 				attempt_transfer(p, p->refer_call);
 				if (p->refer_call->owner)
-					ast_mutex_unlock(&p->refer_call->owner->lock);
+					ast_channel_unlock(p->refer_call->owner);
 				ast_mutex_unlock(&p->refer_call->lock);
 				p->refer_call = NULL;
 				ast_set_flag(p, SIP_GOTREFER);	
@@ -9821,14 +9825,14 @@
 							/* Must release c's lock now, because it will not longer
 							    be accessible after the transfer! */
 							*nounlock = 1;
-							ast_mutex_unlock(&c->lock);
+							ast_channel_unlock(c);
 							sip_park(transfer_to, c, req);
 							nobye = 1;
 						} else {
 							/* Must release c's lock now, because it will not longer
 							    be accessible after the transfer! */
 							*nounlock = 1;
-							ast_mutex_unlock(&c->lock);
+							ast_channel_unlock(c);
 							ast_async_goto(transfer_to,p->context, p->refer_to,1);
 						}
 					} else {
@@ -10354,7 +10358,7 @@
 	p = find_call(&req, &sin, req.method);
 	if (p) {
 		/* Go ahead and lock the owner if it has one -- we may need it */
-		if (p->owner && ast_mutex_trylock(&p->owner->lock)) {
+		if (p->owner && ast_channel_trylock(p->owner)) {
 			ast_log(LOG_DEBUG, "Failed to grab lock, trying again...\n");
 			ast_mutex_unlock(&p->lock);
 			ast_mutex_unlock(&netlock);
@@ -10372,7 +10376,7 @@
 		nounlock = 0;
 		handle_request(p, &req, &sin, &recount, &nounlock);
 		if (p->owner && !nounlock)
-			ast_mutex_unlock(&p->owner->lock);
+			ast_channel_unlock(p->owner);
 		ast_mutex_unlock(&p->lock);
 	}
 	ast_mutex_unlock(&netlock);
@@ -10474,7 +10478,7 @@
 							  (t > sip->lastrtprx + sip->rtpholdtimeout))) {
 						/* Needs a hangup */
 						if (sip->rtptimeout) {
-							while(sip->owner && ast_mutex_trylock(&sip->owner->lock)) {
+							while (sip->owner && ast_channel_trylock(sip->owner)) {
 								ast_mutex_unlock(&sip->lock);
 								usleep(1);
 								ast_mutex_lock(&sip->lock);
@@ -10483,7 +10487,7 @@
 								ast_log(LOG_NOTICE, "Disconnecting call '%s' for lack of RTP activity in %ld seconds\n", sip->owner->name, (long)(t - sip->lastrtprx));
 								/* Issue a softhangup */
 								ast_softhangup(sip->owner, AST_SOFTHANGUP_DEV);
-								ast_mutex_unlock(&sip->owner->lock);
+								ast_channel_unlock(&sip->owner);
 							}
 						}
 					}
@@ -11867,15 +11871,15 @@
 		ast_log(LOG_WARNING, "This application requires the argument: info, inband, rfc2833\n");
 		return 0;
 	}
-	ast_mutex_lock(&chan->lock);
+	ast_channel_lock(chan);
 	if (chan->type != channeltype) {
 		ast_log(LOG_WARNING, "Call this application only on SIP incoming calls\n");
-		ast_mutex_unlock(&chan->lock);
+		ast_channel_unlock(chan);
 		return 0;
 	}
 	p = chan->tech_pvt;
 	if (!p) {
-		ast_mutex_unlock(&chan->lock);
+		ast_channel_unlock(chan);
 		return 0;
 	}
 	ast_mutex_lock(&p->lock);
@@ -11902,7 +11906,7 @@
 		}
 	}
 	ast_mutex_unlock(&p->lock);
-	ast_mutex_unlock(&chan->lock);
+	ast_channel_unlock(chan);
 	return 0;
 }
 
@@ -11920,7 +11924,7 @@
 		ast_log(LOG_WARNING, "This application requires the argument: Header\n");
 		return 0;
 	}
-	ast_mutex_lock(&chan->lock);
+	ast_channel_lock(chan);
 
 	/* Check for headers */
 	while (!ok && no <= 50) {
@@ -11938,7 +11942,7 @@
 	} else {
 		ast_log(LOG_WARNING, "Too many SIP headers added, max 50\n");
 	}
-	ast_mutex_unlock(&chan->lock);
+	ast_channel_unlock(chan);
 	return 0;
 }
 
@@ -11970,10 +11974,10 @@
 		return 0;
 	}
 
-	ast_mutex_lock(&chan->lock);
+	ast_channel_lock(chan);
 	if (chan->type != channeltype) {
 		ast_log(LOG_WARNING, "Call this application only on incoming SIP calls\n");
-		ast_mutex_unlock(&chan->lock);
+		ast_channel_unlock(chan);
 		return 0;
 	}
 
@@ -11986,7 +11990,7 @@
 		ast_goto_if_exists(chan, chan->context, chan->exten, chan->priority + 101);
 	}
 	
-	ast_mutex_unlock(&chan->lock);
+	ast_channel_unlock(chan);
 	return 0;
 }