[Home]

Summary:ASTERISK-28011: chan_sip: get_refer_info() attempted unlock mutex 'peer' without owning it!
Reporter:Alec Davis (alecdavis)Labels:
Date Opened:2018-08-15 22:53:31Date Closed:2018-08-23 08:06:59
Priority:TrivialRegression?No
Status:Closed/CompleteComponents:Channels/chan_sip/General
Versions:13.22.0 Frequency of
Occurrence
Constant
Related
Issues:
Environment:Attachments:
Description:Nothing untoward seems to happen but plays havoc with my OCD by seeing these {color:red}ERRORS{color} go by.

Very repeatable, every time we blind transfer to another SIP device we get
{code}
[2018-08-16 15:37:07.696431] ERROR[2696][C-00001a16]: lock.c:461 __ast_pthread_mutex_unlock: chan_sip.c line 18683 (get_refer_info): mutex 'peer' freed more times than we've locked!
[2018-08-16 15:37:07.696746] ERROR[2696][C-00001a16]: lock.c:492 __ast_pthread_mutex_unlock: chan_sip.c line 18683 (get_refer_info): Error releasing mutex: Operation not permitted
{code}

or
{code}
 == Extension Changed 8512[phones] new state Hold for Notify User cisco1
[2018-08-14 14:49:42.708375] ERROR[2696][C-000014f3]: lock.c:450 __ast_pthread_mutex_unlock: chan_sip.c line 18683 (get_refer_info): attempted unlock mutex 'peer' without owning it!
[2018-08-14 14:49:42.708579] ERROR[2696][C-000014f3]: lock.c:452 __ast_pthread_mutex_unlock: channel.c line 3813 (__ast_read): 'peer' was locked here.
[2018-08-14 14:49:42.709197] ERROR[2696][C-000014f3]: lock.c:58 __dump_backtrace: /usr/sbin/asterisk(__ast_bt_get_addresses+0x14) [0x80a02c8]
   -- Channel SIP/jeremy-00001c67 left 'simple_bridge' basic-bridge <6c720cbf-7f7b-4ff6-9d7f-b51bb4cc3232>
[2018-08-14 14:49:42.709668] ERROR[2696][C-000014f3]: lock.c:58 __dump_backtrace: /usr/sbin/asterisk(__ast_pthread_mutex_lock+0x8a) [0x8153d9c]
[2018-08-14 14:49:42.710482] ERROR[2696][C-000014f3]: lock.c:58 __dump_backtrace: /usr/sbin/asterisk(__ao2_lock+0x70) [0x8096e94]
[2018-08-14 14:49:42.710747] ERROR[2696][C-000014f3]: lock.c:58 __dump_backtrace: /usr/sbin/asterisk(pbx_builtin_setvar_helper+0xd3) [0x819eae8]
[2018-08-14 14:49:42.711242] ERROR[2696][C-000014f3]: lock.c:58 __dump_backtrace: /usr/lib/asterisk/modules/chan_sip.so(+0x5156c) [0xb50c656c]
[2018-08-14 14:49:42.711501] ERROR[2696][C-000014f3]: lock.c:58 __dump_backtrace: /usr/lib/asterisk/modules/chan_sip.so(+0x74ff7) [0xb50e9ff7]
[2018-08-14 14:49:42.711815] ERROR[2696][C-000014f3]: lock.c:58 __dump_backtrace: /usr/lib/asterisk/modules/chan_sip.so(+0x7d4a4) [0xb50f24a4]
[2018-08-14 14:49:42.712273] ERROR[2696][C-000014f3]: lock.c:58 __dump_backtrace: /usr/lib/asterisk/modules/chan_sip.so(+0x7ddf1) [0xb50f2df1]
[2018-08-14 14:49:42.712719] ERROR[2696][C-000014f3]: lock.c:58 __dump_backtrace: /usr/lib/asterisk/modules/chan_sip.so(+0x7d9da) [0xb50f29da]
[2018-08-14 14:49:42.713212] ERROR[2696][C-000014f3]: lock.c:58 __dump_backtrace: /usr/sbin/asterisk(ast_io_wait+0x131) [0x814c20a]
[2018-08-14 14:49:42.713610] ERROR[2696][C-000014f3]: lock.c:58 __dump_backtrace: /usr/lib/asterisk/modules/chan_sip.so(+0x7f870) [0xb50f4870]
[2018-08-14 14:49:42.714093] ERROR[2696][C-000014f3]: lock.c:58 __dump_backtrace: /usr/sbin/asterisk() [0x81fcb38]
[2018-08-14 14:49:42.714443] ERROR[2696][C-000014f3]: lock.c:58 __dump_backtrace: /lib/i386-linux-gnu/i686/cmov/libpthread.so.0(+0x6ecb) [0xb7217ecb]
[2018-08-14 14:49:42.714824] ERROR[2696][C-000014f3]: lock.c:58 __dump_backtrace: /lib/i386-linux-gnu/i686/cmov/libc.so.6(clone+0x5e) [0xb6fdbd0e]
[2018-08-14 14:49:42.715134] ERROR[2696][C-000014f3]: lock.c:492 __ast_pthread_mutex_unlock: chan_sip.c line 18683 (get_refer_info): Error releasing mutex: Operation not permitted
[2018-08-14 14:49:42.715276] ERROR[16109][C-000014f3]: lock.c:461 __ast_pthread_mutex_unlock: channel.c line 3882 (__ast_read): mutex 'chan' freed more times than we've locked!
{code}

I believe the fix is at line 18683 of chan_sip where ast_channel_unlock(peer) is called where it should be ast_channel_unref(peer).
Comments:By: Asterisk Team (asteriskteam) 2018-08-15 22:53:33.314-0500

Thanks for creating a report! The issue has entered the triage process. That means the issue will wait in this status until a Bug Marshal has an opportunity to review the issue. Once the issue has been reviewed you will receive comments regarding the next steps towards resolution.

A good first step is for you to review the [Asterisk Issue Guidelines|https://wiki.asterisk.org/wiki/display/AST/Asterisk+Issue+Guidelines] if you haven't already. The guidelines detail what is expected from an Asterisk issue report.

Then, if you are submitting a patch, please review the [Patch Contribution Process|https://wiki.asterisk.org/wiki/display/AST/Patch+Contribution+Process].

By: Benjamin Keith Ford (bford) 2018-08-16 10:13:34.272-0500

[~alecdavis] chan_sip is now under community support, so any work done on this issue would come from IRC, the dev-list, a bug bounty, or another interested party. If you yourself would like to work on the issue, you can sign up for a Gerrit account and upload your changes for review. The process for doing this can be found here [1].

[1] https://wiki.asterisk.org/wiki/display/AST/Gerrit+Usage

By: Alec Davis (alecdavis) 2018-08-16 16:21:53.431-0500

@Benjamin, thanks - yeah, I know the drill, just have been quiet for a number of years.

Changing ast_channel_unlock(peer) to ast_channel_unref(peer) was not good, asterisk crashes.

Commenting out the offending line ast_channel_unlock(peer) is working at this stage.
If that's the right way I'll create a gerrit case.


By: Friendly Automation (friendly-automation) 2018-08-23 08:06:59.803-0500

Change 9988 merged by Jenkins2:
chan_sip:  remove unnecessary ast_channel_unlock(peer) as RAII looks after it

[https://gerrit.asterisk.org/9988|https://gerrit.asterisk.org/9988]

By: Friendly Automation (friendly-automation) 2018-08-24 09:00:51.806-0500

Change 9990 merged by George Joseph:
chan_sip:  remove unnecessary ast_channel_unlock(peer) as RAII looks after it

[https://gerrit.asterisk.org/9990|https://gerrit.asterisk.org/9990]