The "trylock" test patch.

[lcr.git] / chan_lcr.c

diff --git a/chan_lcr.c b/chan_lcr.c
index d4510d6..5968733 100644 (file)
--- 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\n", text, 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);
@@ -253,8 +254,9 @@ void chan_lcr_log(int type, const char *file, int line, const char *function, st
        if (ast)
                strncpy(ast_text, ast->name, sizeof(ast_text)-1);
        ast_text[sizeof(ast_text)-1] = '\0';
-       
-       ast_log(type, file, line, function, "[call=%s ast=%s] %s", call_text, ast_text, buffer);
+
+printf("\n[call=%s ast=%s] %s\n", call_text, ast_text, buffer);
+//     ast_log(type, file, line, function, "[call=%s ast=%s] %s", call_text, ast_text, buffer);
 
        ast_mutex_unlock(&log_lock);
        lock_debug("l");
@@ -1263,6 +1265,7 @@ int receive_message(int message_type, unsigned int ref, union parameter *param)
        if (message_type == MESSAGE_BCHANNEL) {
                switch(param->bchannel.type) {
                        case BCHANNEL_ASSIGN:
+lock_debug("rx1");
                        CDEBUG(NULL, NULL, "Received BCHANNEL_ASSIGN message. (handle=%08lx) for ref %d\n", param->bchannel.handle, ref);
                        if ((bchannel = find_bchannel_handle(param->bchannel.handle))) {
                                CERROR(NULL, NULL, "bchannel handle %x already assigned.\n", (int)param->bchannel.handle);
@@ -1527,16 +1530,23 @@ static int handle_socket(struct lcr_fd *fd, unsigned int what, void *instance, i
        struct admin_list *admin;
        struct admin_message msg;
 
+       lock_debug("handle+");
        if ((what & LCR_FD_READ)) {
                /* read from socket */
+               lock_debug("handle1");
                len = read(lcr_sock, &msg, sizeof(msg));
+               lock_debug("handle2");
                if (len == 0) {
                        CERROR(NULL, NULL, "Socket closed.\n");
                        error:
                        CERROR(NULL, NULL, "Handling of socket failed - closing for some seconds.\n");
+                       lock_debug("handle3");
                        close_socket();
+                       lock_debug("handle4");
                        release_all_calls();
+                       lock_debug("handle5");
                        schedule_timer(&socket_retry, SOCKET_RETRY_TIMER, 0);
+                       lock_debug("handle-");
                        return 0;
                }
                if (len > 0) {
@@ -1548,7 +1558,9 @@ static int handle_socket(struct lcr_fd *fd, unsigned int what, void *instance, i
                                CERROR(NULL, NULL, "Socket received illegal message %d.\n", msg.message);
                                goto error;
                        }
+                       lock_debug("handleX");
                        receive_message(msg.u.msg.type, msg.u.msg.ref, &msg.u.msg.param);
+                       lock_debug("handleY");
                } else {
                        CERROR(NULL, NULL, "Socket failed (errno %d).\n", errno);
                        goto error;
@@ -1559,10 +1571,13 @@ static int handle_socket(struct lcr_fd *fd, unsigned int what, void *instance, i
                /* write to socket */
                if (!admin_first) {
                        socket_fd.when &= ~LCR_FD_WRITE;
+                       lock_debug("handle-");
                        return 0;
                }
+               lock_debug("handle6");
                admin = admin_first;
                len = write(lcr_sock, &admin->msg, sizeof(msg));
+               lock_debug("handle7");
                if (len == 0) {
                        CERROR(NULL, NULL, "Socket closed.\n");
                        goto error;
@@ -1573,6 +1588,7 @@ static int handle_socket(struct lcr_fd *fd, unsigned int what, void *instance, i
                                goto error;
                        }
                        /* free head */
+                       lock_debug("handle8");
                        admin_first = admin->next;
                        free(admin);
                        global_change = 1;
@@ -1582,6 +1598,7 @@ static int handle_socket(struct lcr_fd *fd, unsigned int what, void *instance, i
                }
        }
 
+       lock_debug("handle-");
        return 0;
 }
 
@@ -1654,9 +1671,11 @@ static int wake_event(struct lcr_fd *fd, unsigned int what, void *instance, int
 {
        char byte;
 
+       lock_debug("wake+");
        read(wake_pipe[0], &byte, 1);
 
        wake_global = 0;
+       lock_debug("wake-");
 
        return 0;
 }
@@ -1673,8 +1692,13 @@ static void handle_queue()
                p = call->queue_string;
                ast = call->ast;
                if (*p && ast) {
-                       lock_debug("A1");
-                       ast_channel_lock(ast);
+                       lock_debug("A1+");
+                       while (ast_channel_trylock(ast)) {
+                               lock_debug("<trylock failed>");
+                               usleep(1000);
+                               lock_debug("A1++");
+                       }
+                       lock_debug("A1-");
                        while(*p) {
                                switch (*p) {
                                case 'T':
@@ -1748,8 +1772,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 +1802,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 +1837,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 +1932,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
@@ -1992,8 +2020,8 @@ static void send_digit_to_chan(struct ast_channel * ast, char digit )
                 ast_playtones_start(ast,0,dtmf_tones[15], 0);
         else {
                 /* not handled */
-                ast_log(LOG_DEBUG, "Unable to handle DTMF tone "
-                       "'%c' for '%s'\n", digit, ast->name);
+//                ast_log(LOG_DEBUG, "Unable to handle DTMF tone "
+//                     "'%c' for '%s'\n", digit, ast->name);
         }
 }
 
@@ -2016,8 +2044,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 +2090,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 +2127,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 +2173,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 +2238,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 +2260,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);
@@ -2238,13 +2272,16 @@ static struct ast_frame *lcr_read(struct ast_channel *ast)
        if (call->pipe[0] > -1) {
                if (call->rebuffer && !call->hdlc) {
                        /* Make sure we have a complete 20ms (160byte) frame */
+                       lock_debug("*1");
                        len=read(call->pipe[0],call->read_buff + call->framepos, 160 - call->framepos);
                        if (len > 0) {
                                call->framepos += len;
                        }
                } else {
+                       lock_debug("*2");
                        len = read(call->pipe[0], call->read_buff, sizeof(call->read_buff));
                }
+               lock_debug("*3");
                if (len < 0 && errno == EAGAIN) {
                        ast_mutex_unlock(&chan_lock);
                        lock_debug("a9");
@@ -2298,8 +2335,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");
@@ -2450,8 +2488,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");
@@ -2475,8 +2514,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");
@@ -2515,8 +2555,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) {
@@ -2633,8 +2674,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) {
@@ -2786,8 +2828,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);
@@ -2989,8 +3032,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");