Added counter for unhandled_bmsg Print, this prevents the logs to be flooded to fast and save CPU in this error scenario. Added 'last_used' element to bc structure, when a bchannel changes from used to free this exact time will be marked in last_used. When a new channel is requested the find_free_chan function will check if the new empty channel was used within the last second, if yes it will search for the next channel, if no it will return this channel. This simple mechanism has prooven to prevent race conditions where the NT and TE tried to allocate the exact same channel at the same time (RELEASE cause: 44).

git-svn-id: http://svn.digium.com/svn/asterisk/branches/1.4@119585 f38db490-d61c-443f-a65b-d21fe96a405b

2 files changed, 44 insertions, 4 deletions

diff --git a/channels/misdn/isdn_lib.c b/channels/misdn/isdn_lib.c
index 64b92f66a..6259f9bcf 100644
--- a/channels/misdn/isdn_lib.c
+++ b/channels/misdn/isdn_lib.c
@@ -13,6 +13,7 @@
 
 
 #include <syslog.h>
+#include <sys/time.h>
 #include <mISDNuser/isdn_debug.h>
 
 #include "isdn_lib_intern.h"
@@ -700,6 +701,8 @@ static void empty_bc(struct misdn_bchannel *bc)
 	
 	bc->te_choose_channel = 0;
 	bc->channel_found= 0;
+
+	gettimeofday(&bc->last_used, NULL);
 }
 
 
@@ -1565,7 +1568,17 @@ static int handle_event ( struct misdn_bchannel *bc, enum event_e event, iframe_
 					break;
 				}
 
-				cb_log(0, stack->port, "Any Channel Requested, but we have no more!!\n");
+				if (!bc->channel)
+					cb_log(0, stack->port, "Any Channel Requested, but we have no more!!\n");
+				else 
+					cb_log(0, stack->port, "Requested Channel Already in Use releasing this call with cause 34!!!!\n");
+
+				/* when the channel is already in use, we can't
+				 * simply clear it, we need to make sure that 
+				 * it will still be marked as in_use in the 
+				 * available channels list.*/
+				bc->channel=0;
+
 				misdn_lib_send_event(bc,EVENT_RELEASE_COMPLETE);
 				return -1;
 			}
@@ -3092,6 +3105,20 @@ struct misdn_bchannel *manager_find_bc_holded(struct misdn_bchannel* bc)
 
 
 
+int test_inuse(struct misdn_bchannel *bc)
+{
+	struct timeval now;
+	gettimeofday(&now, NULL);
+	if (!bc->in_use) {
+		if (bc->last_used.tv_sec < now.tv_sec) {
+			cb_log(0,bc->port, "channel with stid:%x for one second still in use!\n", bc->b_stid);
+			return 1;
+		}
+	}
+	return 0;
+}
+
+
 static void prepare_bc(struct misdn_bchannel*bc, int channel)
 {
 	bc->channel = channel;
@@ -3122,6 +3149,8 @@ struct misdn_bchannel* misdn_lib_get_free_bc(int port, int channel, int inout, i
 		return NULL;
 	}
 
+	usleep(1000);
+
 	for (stack=glob_mgr->stack_list; stack; stack=stack->next) {
     
 		if (stack->port == port) {
@@ -3134,7 +3163,7 @@ struct misdn_bchannel* misdn_lib_get_free_bc(int port, int channel, int inout, i
 			if (channel > 0) {
 				if (channel <= stack->b_num) {
 					for (i = 0; i < stack->b_num; i++) {
-						if (stack->bc[i].in_use && stack->bc[i].channel == channel) {
+						if ( test_inuse(&stack->bc[i]) && stack->bc[i].channel == channel) {
 							cb_log(0,port,"Requested channel:%d on port:%d is already in use\n",channel, port);
 							return NULL;
 						}
@@ -3149,7 +3178,7 @@ struct misdn_bchannel* misdn_lib_get_free_bc(int port, int channel, int inout, i
 
 			if (dec) {
 				for (i = maxnum-1; i>=0; i--) {
-					if (!stack->bc[i].in_use) {
+					if (test_inuse(&stack->bc[i])) {
 						/* 3. channel on bri means CW*/
 						if (!stack->pri && i==stack->b_num)
 							stack->bc[i].cw=1;
@@ -3161,7 +3190,7 @@ struct misdn_bchannel* misdn_lib_get_free_bc(int port, int channel, int inout, i
 				}
 			} else {
 				for (i = 0; i <maxnum; i++) {
-					if (!stack->bc[i].in_use) {
+					if (test_inuse(&stack->bc[i])) {
 						/* 3. channel on bri means CW*/
 						if (!stack->pri && i==stack->b_num)
 							stack->bc[i].cw=1;
@@ -3581,9 +3610,19 @@ int manager_isdn_handler(iframe_t *frm ,msg_t *msg)
 	}
 
 	if ( ((frm->addr | ISDN_PID_BCHANNEL_BIT )>> 28 ) == 0x5) {
+		static int unhandled_bmsg_count=1000;
 		if (handle_bchan(msg)) {
 			return 0 ;
 		}
+			
+		if (unhandled_bmsg_count==1000) {
+			cb_log(0, 0, "received 1k Unhandled Bchannel Messages: prim %x len %d from addr %x, dinfo %x on this port.\n",frm->prim, frm->len, frm->addr, frm->dinfo);		
+			unhandled_bmsg_count=0;
+		}
+
+		unhandled_bmsg_count++;
+		free_msg(msg);
+		return 0;
 	}	
 
 #ifdef RECV_FRM_SYSLOG_DEBUG
diff --git a/channels/misdn/isdn_lib.h b/channels/misdn/isdn_lib.h
index 22f5d9ff6..8e95b5303 100644
--- a/channels/misdn/isdn_lib.h
+++ b/channels/misdn/isdn_lib.h
@@ -230,6 +230,7 @@ struct misdn_bchannel {
 	int channel_preselected;
 	
 	int in_use;
+	struct timeval last_used;
 	int cw;
 	int addr;