From: Andreas Eversberg <jolly@eversberg.eu>
Date: Mon, 14 Jun 2010 10:31:52 +0000 (+0200)
Subject: Added more detailed debugging for the locking problem.
X-Git-Url: http://git.eversberg.eu/gitweb.cgi?p=lcr.git;a=commitdiff_plain;h=69ad78e230664a2ebf1b70f48981f73a9b81d3f8

Added more detailed debugging for the locking problem.
---

diff --git a/chan_lcr.c b/chan_lcr.c
index c912b80..701d8a2 100644
--- a/chan_lcr.c
+++ b/chan_lcr.c
@@ -227,7 +227,7 @@ void lock_debug(char *text)
 {
 	pthread_t tid = pthread_self();
 //	printf("%s|%03x\n", text, ((tid>>6) | (tid>>3) | tid) & 0xfff); fflush(stdout);
-	printf("%s|%x", text, (int)tid); fflush(stdout);
+	printf(" %s(%x) ", text, (int)tid); fflush(stdout);
 }
 
 /*
@@ -240,8 +240,9 @@ void chan_lcr_log(int type, const char *file, int line, const char *function, st
 	char ast_text[128] = "NULL";
 	va_list args;
 
-	lock_debug("L");
+	lock_debug("L+");
 	ast_mutex_lock(&log_lock);
+	lock_debug("L-");
 
 	va_start(args,fmt);
 	vsnprintf(buffer,sizeof(buffer)-1,fmt,args);
@@ -1673,8 +1674,9 @@ static void handle_queue()
 		p = call->queue_string;
 		ast = call->ast;
 		if (*p && ast) {
-			lock_debug("A1");
+			lock_debug("A1+");
 			ast_channel_lock(ast);
+			lock_debug("A1-");
 			while(*p) {
 				switch (*p) {
 				case 'T':
@@ -1748,8 +1750,9 @@ static int handle_retry(struct lcr_timer *timer, void *instance, int index)
 
 void lock_chan(void)
 {
-	lock_debug("C");
+	lock_debug("C+");
 	ast_mutex_lock(&chan_lock);
+	lock_debug("C-");
 }
 
 void unlock_chan(void)
@@ -1777,8 +1780,9 @@ static void *chan_thread(void *arg)
 	/* open socket the first time */
 	handle_retry(NULL, NULL, 0);
 
-	lock_debug("A2");
+	lock_debug("A2+");
 	ast_mutex_lock(&chan_lock);
+	lock_debug("A2-");
 
 	while(!quit) {
 		handle_queue();
@@ -1811,8 +1815,9 @@ struct ast_channel *lcr_request(const char *type, int format, void *data, int *c
 	struct ast_channel *ast;
         struct chan_call *call;
 
-	lock_debug("A3");
+	lock_debug("A3+");
 	ast_mutex_lock(&chan_lock);
+	lock_debug("A3-");
 	CDEBUG(NULL, NULL, "Received request from Asterisk. (data=%s)\n", (char *)data);
 
 	/* if socket is closed */
@@ -1905,8 +1910,9 @@ static int lcr_call(struct ast_channel *ast, char *dest, int timeout)
 	union parameter newparam;
         struct chan_call *call;
 
-	lock_debug("A4");
+	lock_debug("A4+");
 	ast_mutex_lock(&chan_lock);
+	lock_debug("A4-");
         call = ast->tech_pvt;
         
         #ifdef LCR_FOR_CALLWEAVER
@@ -2016,8 +2022,9 @@ static int lcr_digit(struct ast_channel *ast, char digit)
 	if (digit > 126 || digit < 32)
 		return 0;
 
-	lock_debug("A5");
+	lock_debug("A5+");
 	ast_mutex_lock(&chan_lock);
+	lock_debug("A5-");
         call = ast->tech_pvt;
 	if (!call) {
 		CERROR(NULL, ast, "Received digit from Asterisk, but no call instance exists.\n");
@@ -2061,8 +2068,9 @@ static int lcr_digit_end(struct ast_channel *ast, char digit, unsigned int durat
         struct chan_call *call;
 #endif
 
-	lock_debug("A6");
+	lock_debug("A6+");
 	ast_mutex_lock(&chan_lock);
+	lock_debug("A6-");
 
         call = ast->tech_pvt;
 
@@ -2097,8 +2105,9 @@ static int lcr_answer(struct ast_channel *ast)
 	union parameter newparam;
         struct chan_call *call;
 
-	lock_debug("A7");
+	lock_debug("A7+");
 	ast_mutex_lock(&chan_lock);
+	lock_debug("A7-");
         call = ast->tech_pvt;
 	if (!call) {
 		CERROR(NULL, ast, "Received answer from Asterisk, but no call instance exists.\n");
@@ -2142,8 +2151,9 @@ static int lcr_hangup(struct ast_channel *ast)
 	pthread_t tid = pthread_self();
 
 	if (!pthread_equal(tid, chan_tid)) {
-		lock_debug("H");
+		lock_debug("H+");
 		ast_mutex_lock(&chan_lock);
+		lock_debug("H-");
 	}
         call = ast->tech_pvt;
 	if (!call) {
@@ -2206,8 +2216,9 @@ static int lcr_write(struct ast_channel *ast, struct ast_frame *f)
 	if (!(f->subclass & ast->nativeformats))
 		CDEBUG(NULL, ast, "Unexpected format.\n");
 	
-	lock_debug("A8");
+	lock_debug("A8+");
 	ast_mutex_lock(&chan_lock);
+	lock_debug("A8-");
         call = ast->tech_pvt;
 	if (!call) {
 		ast_mutex_unlock(&chan_lock);
@@ -2227,8 +2238,9 @@ static struct ast_frame *lcr_read(struct ast_channel *ast)
         struct chan_call *call;
 	int len;
 
-	lock_debug("A9");
+	lock_debug("A9+");
 	ast_mutex_lock(&chan_lock);
+	lock_debug("A9-");
         call = ast->tech_pvt;
 	if (!call) {
 		ast_mutex_unlock(&chan_lock);
@@ -2301,8 +2313,9 @@ static int lcr_indicate(struct ast_channel *ast, int cond, const void *data, siz
         struct chan_call *call;
 	const struct tone_zone_sound *ts = NULL;
 
-	lock_debug("A0");
+	lock_debug("A0+");
 	ast_mutex_lock(&chan_lock);
+	lock_debug("A0-");
         call = ast->tech_pvt;
 	if (!call) {
 		CERROR(NULL, ast, "Received indicate from Asterisk, but no call instance exists.\n");
@@ -2453,8 +2466,9 @@ static int lcr_fixup(struct ast_channel *oldast, struct ast_channel *ast)
 		return -1;
 	}
 
-	lock_debug("Af");
+	lock_debug("Af+");
 	ast_mutex_lock(&chan_lock);
+	lock_debug("Af-");
 	call = ast->tech_pvt;
 	if (!call) {
 		CERROR(NULL, ast, "Received fixup from Asterisk, but no call instance exists.\n");
@@ -2478,8 +2492,9 @@ static int lcr_send_text(struct ast_channel *ast, const char *text)
         struct chan_call *call;
 	union parameter newparam;
 
-	lock_debug("At");
+	lock_debug("At+");
 	ast_mutex_lock(&chan_lock);
+	lock_debug("At-");
 	call = ast->tech_pvt;
 	if (!call) {
 		CERROR(NULL, ast, "Received send_text from Asterisk, but no call instance exists.\n");
@@ -2518,8 +2533,9 @@ enum ast_bridge_result lcr_bridge(struct ast_channel *ast1,
 	carr[1] = ast2;
 
 	/* join via dsp (if the channels are currently open) */
-	lock_debug("Ab");
+	lock_debug("Ab+");
 	ast_mutex_lock(&chan_lock);
+	lock_debug("Ab-");
 	call1 = ast1->tech_pvt;
 	call2 = ast2->tech_pvt;
 	if (!call1 || !call2) {
@@ -2636,8 +2652,9 @@ enum ast_bridge_result lcr_bridge(struct ast_channel *ast1,
 	CDEBUG(NULL, NULL, "Releasing bridge.\n");
 
 	/* split channels */
-	lock_debug("Ab");
+	lock_debug("Ab+");
 	ast_mutex_lock(&chan_lock);
+	lock_debug("Ab-");
 	call1 = ast1->tech_pvt;
 	call2 = ast2->tech_pvt;
 	if (call1 && call1->bridge_id) {
@@ -2789,8 +2806,9 @@ static int lcr_config_exec(struct ast_channel *ast, void *data, char **argv)
 {
 	struct chan_call *call;
 
-	lock_debug("Ae");
+	lock_debug("Ae+");
 	ast_mutex_lock(&chan_lock);
+	lock_debug("Ae-");
 
 	#ifdef LCR_FOR_ASTERISK
 	CDEBUG(NULL, ast, "Received lcr_config (data=%s)\n", (char *)data);
@@ -2992,8 +3010,9 @@ int usecount(void)
 hae
 {
 	int res;
-	lock_debug("U");
+	lock_debug("U+");
 	ast_mutex_lock(&usecnt_lock);
+	lock_debug("U-");
 	res = usecnt;
 	ast_mutex_unlock(&usecnt_lock);
 	lock_debug("u");