Summary:ASTERISK-17184: SIP channel tried to release unowned mutex in handle_incoming()
Reporter:Kirill Katsnelson (kkm)Labels:
Date Opened:2010-12-29 20:32:01.000-0600Date Closed:2015-03-15 15:10:14
Versions:Frequency of
Description:Still testing 1.8 pre-production, suddenly received this

[2010-12-29 18:00:34.191] ERROR[17610]: lock.c:384 __ast_pthread_mutex_unlock: chan_sip.c line 23562 (handle_incoming): mutex 'owner' freed more times than we've locked!
[2010-12-29 18:00:34.191] ERROR[17610]: lock.c:416 __ast_pthread_mutex_unlock: chan_sip.c line 23562 (handle_incoming): Error releasing mutex: Operation not permitted

Unfortunately, not much debugging information available. That was one of a kind error. The following AEL code has been executed with errors appearing between 2 trace lines:

   &trace(Entering queue - ${QUEUE_STATS}); //<- after this
. . .

macro on-queue-answer() {
 &trace(Answering in $[${CDR(duration)}-${CDR(billsec)}]s on ${CHANNEL}); //<- before this

The call had been answered in the macro

macro answer-nocdr-maybe() {
 if("${CHANNEL(state)}" == "Ring") {


       ast_channel_unlock(owner); //<--- here
       *nounlock = 1;
       pbx_builtin_setvar_helper(owner, causevar, causeval);

I am sorry, this report is very vague. Still I thought it might be worth logging.

Might be related to ASTERISK-1815403. Just a gut feeling.
Comments:By: Jeff Peeler (jpeeler) 2011-01-13 15:12:05.000-0600

Were there any transfers going on when this occurred? This does appear to be related.

By: Matt Kemner (mkemner) 2011-01-13 20:30:33.000-0600

I get this error between 3 and 5 times a day (I am running 1.8.1-rc1, around 300 calls a day) however despite my best efforts I have not been able to replicate it at will - which means I don't have any further debug information.

What I can tell you is that I get the error shortly after making a SIP call to another asterisk (1.2) server. I don't get the error on every call but every time the bug is triggered it is while making a SIP/udp call to another asterisk server.  

What then happens is the asterisk1.2 believes the call is still in progress (so the phone on that server keeps ringing) even after the 1.8 server has hung up.  

I have around a dozen phones connected via SIP/TCP to the 1.8 server, all using blf, so the server is busy updating extension states at the time of the call (which may be a factor) - however I never see the bug when calling one of the local phones so it's either something that only affects SIP/UDP not /TCP or the 1.2 server is doing something 1.8 doesn't like... :)

Also, no transfers are happening at the time.  This can be triggered by something as simple as: extension 101 (on the 1.8 server) dials extension 103 (on the 1.2 server) - the extension is found using DUNDi and 1.8 then dials SIP/103@asterisk12

By: Kirill Katsnelson (kkm) 2011-01-14 12:48:09.000-0600

@jpeeler: No, no transfer. Sorry, I had a wrong idea at the time. Or maybe it was just 4AM already...

By: Kirill Katsnelson (kkm) 2011-01-14 12:53:25.000-0600

In my case, it happened while receiving a SIP call from a customer trunk. They are Avaya IPO 500, and we are registering to their box if that matters.

MKemner, can you be the tester of the fix when available? I am not getting that error any more. It was really one of a kind error (not much load on the preproduction server though).

By: Matt Kemner (mkemner) 2011-01-19 00:46:32.000-0600

I sure can. I upgraded to 1.8.2 last night, and am still getting the error, although only once so far today (quiet day, only 180 calls so far)

By: Joshua C. Colp (jcolp) 2015-03-15 15:10:02.799-0500

Per the Asterisk versions page [1], the maintenance (bug fix) support for the Asterisk branch you are using has ended. For continued maintenance support please move to a supported branch of Asterisk. After testing with a supported branch, if you find this problem has not been resolved, please open a new issue against the latest version of that Asterisk branch.


[1] https://wiki.asterisk.org/wiki/display/AST/Asterisk+Versions