[Home]

Summary:ASTERISK-06638: [patch] devicestate problem
Reporter:Andrey S Pankov (casper)Labels:
Date Opened:2006-03-28 10:16:26.000-0600Date Closed:2006-04-10 13:58:45
Priority:MinorRegression?No
Status:Closed/CompleteComponents:Core/General
Versions:Frequency of
Occurrence
Related
Issues:
Environment:Attachments:
Description:It seems like if we hold c->lock when calling ast_setstate there is no way devicestate could be changed.

****** ADDITIONAL INFORMATION ******

Mar 28 18:39:57 DEBUG[17001]: chan_sip.c:10945 handle_request: **** Received INVITE (5) - Command in SIP INVITE
Mar 28 18:39:57 DEBUG[17001]: chan_sip.c:7015 check_user_full: Setting NAT on RTP to 524288
Mar 28 18:39:57 DEBUG[17001]: chan_sip.c:10327 handle_request_invite: Checking SIP call limits for device 1000
Mar 28 18:39:57 DEBUG[17001]: chan_sip.c:2199 update_call_counter: Updating call counter for incoming call
Mar 28 18:39:57 DEBUG[17001]: chan_sip.c:6025 build_route: build_route: Contact hop: 1000 <sip:1000@192.168.1.122:5060;user=phone;transport=udp>
Mar 28 18:39:57 DEBUG[16985]: chan_sip.c:11472 sip_devicestate: Checking device state for peer 1000
Mar 28 18:39:57 DEBUG[16985]: channel.c:777 channel_find_locked: Avoiding initial deadlock for 'SIP/1000-aff8'              
...
Mar 28 18:39:57 WARNING[16985]: channel.c:787 channel_find_locked: Avoided initial deadlock for '0x8158a30', 10 retries!    
Comments:By: Andrey S Pankov (casper) 2006-03-28 10:17:58.000-0600

Normal scenario is:
Mar 28 18:58:07 DEBUG[17268]: chan_sip.c:10947 handle_request: **** Received INVITE (5) - Command in SIP INVITE
Mar 28 18:58:07 DEBUG[17268]: chan_sip.c:7015 check_user_full: Setting NAT on RTP to 524288
Mar 28 18:58:07 DEBUG[17268]: chan_sip.c:10327 handle_request_invite: Checking SIP call limits for device 1000
Mar 28 18:58:07 DEBUG[17268]: chan_sip.c:2199 update_call_counter: Updating call counter for incoming call
Mar 28 18:58:07 DEBUG[17268]: chan_sip.c:6025 build_route: build_route: Contact hop: 1000 <sip:1000@192.168.1.122:5060;user=phone;transport=udp>
Mar 28 18:58:07 DEBUG[16985]: chan_sip.c:11474 sip_devicestate: Checking device state for peer 1000
Mar 28 18:58:07 DEBUG[16985]: devicestate.c:187 do_state_change: Changing state for SIP/1000 - state 2 (In use)
By: Andrey S Pankov (casper) 2006-03-28 10:19:45.000-0600

I'd proposed smth like this, but I'm not sure this is the right way to fix this... oej? Thanks in advance.

--- chan_sip.c.bak      2006-03-16 23:32:42.000000000 +0200
+++ chan_sip.c  2006-03-28 18:55:45.000000000 +0300
@@ -10388,11 +10388,13 @@
               ast_channel_setwhentohangup (c, p->osptimelimit);
#endif
               switch(c->_state) {
               case AST_STATE_DOWN:
                       transmit_response(p, "100 Trying", req);
+                       ast_mutex_unlock(&c->lock);
                       ast_setstate(c, AST_STATE_RING);
+                       ast_mutex_lock(&c->lock);
                       if (strcmp(p->exten, ast_pickup_ext())) {
                               enum ast_pbx_result res;

                               res = ast_pbx_start(c);

Anyway, this is not the right fix... :( we need at least usleep() before locking the mutex again in order devicestate gets updated, but this is too ugly.


By: Olle Johansson (oej) 2006-03-28 18:57:04.000-0600

Are you using a clean Asterisk or have you integrated the SNOM patch for blinking lights? That patch is not good at all and will cause a lot of problems like this.
By: Andrey S Pankov (casper) 2006-03-29 06:41:57.000-0600

It's vanilla 1.2.4
By: Andrey S Pankov (casper) 2006-03-29 07:14:24.000-0600

This problem is a global one. It is not related to SIP channel only but to entire devicestate subsystem. If DEBUG is turned on we'll always see "Avoiding initial deadlock" message from time to time. Let's look at ast_answer code: there will be at least one such a message because we hold chan->lock when calling ast_setstate, but release it shortly after. That's why channel_find_locked will not fail after 10 retries for that channel, but there will be at least one fail. And this is intended behavior.

It turned out that the situation discribed (channel_find_locked fail after 10 attempts) occurs only with smth like 'exten => XXX,1,Hangup()'.
By: Andrey S Pankov (casper) 2006-04-10 13:48:02

Let's close the issue. Thanks!