Summary:	ASTERISK-11890: State problems on queues with Direct and Local Agents
Reporter:	Doug (doug)	Labels:
Date Opened:	2008-04-22 07:24:42	Date Closed:	2009-01-13 16:06:56.000-0600
Priority:	Major	Regression?	No
Status:	Closed/Complete	Components:	Channels/chan_agent
Versions:		Frequency of Occurrence
Related Issues:
Environment:		Attachments:	( 0) debug ( 1) queues.conf ( 2) sip.conf
Description:	We have a few systems that experiance this problem on both Local and Direct channela. The queue will report the agent as "in use" or "not in use" but will not update the status when the call ends. This causes major problems when the state if leaft in "in use" as no calls will be passed to the agent. We get a constant error: Apr 22 11:34:44] WARNING[4322] app_queue.c: The device state of this queue member, SIP/8033, is still 'Not in Use' when it probably should not be! Please check UPGRADE.txt for correct configuration settings. I am unable to find the reason for this error. I have attached a debug on level 3 with verbose on level 3.
Comments:	By: Joel Vandal (jvandal) 2008-04-22 09:05:05 One thing that I've notice is that each time a channel look "hang", (i.e. that the agent doesnt receive new call and status is set to 'Not In Use' on 'show queues'), on 'sip show channels' we see Tx: ACK as Last Message for all channels that look "hang". 192.168.99.15    1012        34ab625e1b0  00102/00000  0x4 (ulaw)       No       Tx: ACK 192.168.99.15    1005        10e0be99257  00102/00000  0x4 (ulaw)       No       Tx: ACK 192.168.99.15    1007        5e52e7b84ed  00102/00000  0x4 (ulaw)       No       Tx: ACK 192.168.99.15    1013        2fca85793c1  00102/00000  0x4 (ulaw)       No       Tx: ACK 192.168.99.15    1002        5a0b8210115  00102/00000  0x4 (ulaw)       No       Tx: ACK By: Jared Smith (jsmith) 2008-04-22 10:15:17 jvandal, Your issue may be different... grab a developer on IRC (freenode.net) in the #asterisk-bugs channel and they'll show you how to turn on SIP history so we can find out if/why you're having stuck SIP channels. By: Jason Parker (jparker) 2008-04-22 13:52:24 Out of curiosity, how did you create the 'debug' attachment?  It turned every instance of "**" into a list of files. By: Doug (doug) 2008-04-22 14:34:08 The original file was full of: [Apr 22 11:38:05] DEBUG[8847] audiohook.c: Write factory 0x8ce9c7c was pretty quick last time, waiting for them. [Apr 22 11:38:05] DEBUG[4037] audiohook.c: Read factory 0x8cd6430 was pretty quick last time, waiting for them. So used the below command to filter out only the usfull info: cat full | while read LINE; do BOB=`echo ${LINE} | grep -i "audiohook.c"; echo $?`; if [ "${BOB}" -eq "1" ]; then echo $LINE >> test; fi; done By: Doug (doug) 2008-04-24 09:47:15 This problem was caused by the Autofill = no option in queues.conf. When set to no this caused a problem with agent state refreshing. Ticket can be closed. By: Jason Parker (jparker) 2008-04-24 11:30:46 Closing per reporter. By: Doug (doug) 2008-04-30 06:34:44 This issue was not resolved by autofill as previously thought. The problem has come back. Please if anyone can help here I have attached the debug output and can collect any needed info. We are running Local channel now and have this problem again. By: Phillip Smith (phillip) 2008-04-30 06:43:35 I have attached both the sip.conf and queues.conf, and out of intrest we are using AddQueueMember to login our agents. Please let us know if there is any other information to help identify this problem. By: Doug (doug) 2008-04-30 06:57:19 watching the server i have just seen this lock error. Im not sure if it has to do with the same problem? [Apr 30 13:46:55] ERROR[30020]: /dar/build/asterisk-1.4.19/include/asterisk/lock.h:462 __ast_pthread_mutex_unlock: chan_local.c line 188 (local_queue_frame): mutex '&us->lock' freed more times than we've locked! [Apr 30 13:46:55] ERROR[30020]: /dar/build/asterisk-1.4.19/include/asterisk/lock.h:479 __ast_pthread_mutex_unlock: chan_local.c line 188 (local_queue_frame): Error releasing mutex: Operation not permitted By: Doug (doug) 2008-05-05 02:44:12 Again I have lock errors: [May  5 09:36:32] ERROR[6008]: /dar/build/asterisk-1.4.19/include/asterisk/lock.h:462 __ast_pthread_mutex_unlock: chan_local.c line 188 (local_queue_frame): mutex '&us->lock' freed more times than we've locked! [May  5 09:36:32] ERROR[6008]: /dar/build/asterisk-1.4.19/include/asterisk/lock.h:479 __ast_pthread_mutex_unlock: chan_local.c line 188 (local_queue_frame): Error releasing mutex: Operation not permitted [May  5 09:37:15] ERROR[6008]: /dar/build/asterisk-1.4.19/include/asterisk/lock.h:281 __ast_pthread_mutex_destroy: channel.c line 1258 (ast_channel_free): Error destroying mutex &chan->lock: Device or resource busy By: David Brillert (aragon) 2008-05-28 11:54:50 I believe this issue was fixed in revision 116038 closes issue 12584 related to issue 12603 This bug should be closed? By: Doug (doug) 2008-09-15 09:58:17 This issue is back in full swing, somehow it disappeared for a while but we are seeing the same behavior and same logs as before. I have opted to use a direct channels SIP for our agents to eliminate it being any chan_local related patch such as state interface. This made no difference and we still have the issue. I have added a new ticket 13481 with current info. By: Leif Madsen (lmadsen) 2008-12-09 08:07:04.000-0600 I've reassigned this to putnopvut to take a look at it because I believe he may be best able to determine if this is a device state issue as I had run into previously. Please feel free to reassign as necessary. Thanks! By: Mark Michelson (mmichelson) 2008-12-09 16:48:14.000-0600 Given the version reported initially in this issue, I think the problem has been fixed already in the 1.4 branch. The biggest commit that I think will fix this issue is 133649. I would like if this issue could be tested with a more up-to-date copy of 1.4 so that this may be confirmed. By: David Brillert (aragon) 2008-12-31 17:25:13.000-0600 DougUDI and I use unsupported state_interface backport from 1.6 We also used a backport of shared_wrap from 1.6 State_interface backport is working nicely and DougUDI and my problems were caused by bad backport of shared_wrap from 1.6 Since we have removed bad backport of shared_wrap we no longer have any issues with symptoms like app_queue.c: The device state of this queue member, SIP/8033, is still 'Not in Use' when it probably should not be! Please check UPGRADE.txt for correct configuration settings. state_interface was necessary for our environments since we are not convinced upgrading to 1.6 in our production servers is such a great idea at this time. By: David Brillert (aragon) 2008-12-31 17:31:30.000-0600 Also Doug's related ticket 13481 is closed. Putnopvut I think you can close this ticket for same reasons as 13481 since state_interface backport is unsupported in 1.4 and because we also found root cause to be another unsupported backport. P.S. it would be nice to see state_interface officially supported in 1.4 it seems like a colossal waste of time to track so many bug reports in the bugtracker that would be fixed if state_interface were officially supported in 1.4 ;) BTW nice work on state_interface its worth its weight in gold!!! By: Ronald Chan (loloski) 2009-01-01 09:28:24.000-0600 aragon: could you please share a link as to where you get the backport of state_interface for 1.4 does it apply for svn 1.4.22 release or 1.4 svn as well? i one too vouch for official state_interface for 1.4 sorry guys for posting. i'm just desperate to fix the problem in my environment thanks edit: i found it thanks By: Ronald Chan (loloski) 2009-01-02 10:41:41.000-0600 after patching app_queue with backport state_interface patch from 1.6 i can clearly say this really fix the issue :) many thanks to all for bringing up a patch like this. By: Mark Michelson (mmichelson) 2009-01-13 16:06:54.000-0600 I'm closing this based on aragon's suggestion.