[asterisk-bugs] [Asterisk 0014112]: Thread deadlock causes Asterisk to stop routing calls to agents, agents unable to change status

[Asterisk Bug Tracker]

A NOTE has been added to this issue. 
====================================================================== 
http://bugs.digium.com/view.php?id=14112 
====================================================================== 
Reported By:                sroberts
Assigned To:                
====================================================================== 
Project:                    Asterisk
Issue ID:                   14112
Category:                   Channels/chan_agent
Reproducibility:            random
Severity:                   major
Priority:                   normal
Status:                     feedback
Asterisk Version:           1.4.19 
Regression:                 No 
SVN Branch (only for SVN checkouts, not tarball releases): N/A 
SVN Revision (number only!):  
Request Review:              
====================================================================== 
Date Submitted:             2008-12-19 07:16 CST
Last Modified:              2009-03-04 08:43 CST
====================================================================== 
Summary:                    Thread deadlock causes Asterisk to stop routing
calls to agents, agents unable to change status
Description: 
We run several call centres on Asterisk. Our queue servers are using
Asterisk 1.4.19 on CentOS 4.6. The busier sites can take anywhere between
5000 and 10000 calls per day.

We are experiencing a problem whereby occasionally Asterisk will stop
routing calls to agents. If one opens the console and issues a "show
channels" command the channel list does not finish displaying, it only
shows a portion of the channels. The console then becomes unresponsive.
Calls then continue to build up in the queue, and only restarting Asterisk
fixes it.

I have attached a dump of "core show locks". I could not get any further
info this time, as Asterisk must generally be restarted immediately when
this happens to keep the call centre operating. If you look for Thread id
3006892960 you will see that this thread has locked the list of agents
while a whole host of other threads are waiting for this mutex to be
released. I ran "core show locks" 4 times about 2 seconds apart before
restarting and in each case that lock was still being held with many other
threads waiting for it.

The lock in question is in agent_logoff in chan_agent.c. It seems that the
list of agent channels is locked, it then matches the agent channel it is
looking for and then falls into one of the following two loops:

while (p->owner && ast_channel_trylock(p->owner)) {
    ast_mutex_unlock(&p->lock);
    usleep(1);
    ast_mutex_lock(&p->lock);
}

or

while (p->chan && ast_channel_trylock(p->chan)) {
    ast_mutex_unlock(&p->lock);
    usleep(1);
    ast_mutex_lock(&p->lock);
}


It seems as though it is unable to obtain the lock for p->owner or
p->chan, so it keeps looping trying to get the lock. The problem is that
the number of threads waiting for the agent list to be unlocked starts
growing and growing as more and more calls pour into the queue. Obviously
because the list of agents is locked, calls can't be routed. 

This problem seems to happen every 2 to 3 weeks and generally occurs only
when the box is receiving a lot of calls.

Any suggestions/advice would be greatly appreciated.




====================================================================== 

---------------------------------------------------------------------- 
 (0101182) sroberts (reporter) - 2009-03-04 08:43
 http://bugs.digium.com/view.php?id=14112#c101182 
---------------------------------------------------------------------- 
Hi again,

I think I have this figured out now.

When a hangup occurs, agent_devicestate_cb is called to update the state
of the agent. This then obtains a lock on the agent_list. It then begins
it's traversal of the list, blocking for each agent in the list until it
gets the lock - ast_mutex_lock(&p->lock). 

What happens at the same time is that ast_hangup is being called, now one
of the functions called in that stack is local_hangup. Inside local_hangup
is a lockup waiting to happen:

while (ast_mutex_trylock(&p->lock)) {
		ast_channel_unlock(ast);
		usleep(1);
		ast_channel_lock(ast);
}

In the case of what happened to me today, this now sits looping and
waiting for a lock being held in ast_indicate_data, while ast_indicate_data
is waiting for a lock being held by local_hangup.

A quick glance at thread id's 3004504992 and 2981165984 in locks5 shows
this.

Thread 194 in the gdb trace shows this as well. 

So while these two threads are waiting for each other to release their
respective locks, agent_devicestate_cb waits for this to finish, while
holding it's lock on the channel list. If you look at the locks5 file, you
can see hundreds of other threads blocking waiting for the agent list to be
released.

Since I haven't had any response, and I have to act I am going to
implement the abovementioned change as well as change the while loop I
mentioned in this post, as well as the other while loop in local_hangup:

while (p->owner && ast_channel_trylock(p->owner)) {
    ast_mutex_unlock(&p->lock);
	if (ast) {
	    ast_channel_unlock(ast);
	}
	usleep(1);
	if (ast) {
	    ast_channel_lock(ast);
	}
	ast_mutex_lock(&p->lock);
}

to use the DEADLOCK_AVOIDANCE macro. Hopefully this will at least stop the
entire call centre grinding to a halt in the event of such lockups. If it
is successful, I will post a patch here in a couple of days time 

Issue History 
Date Modified    Username       Field                    Change               
====================================================================== 
2009-03-04 08:43 sroberts       Note Added: 0101182                          
======================================================================