[asterisk-bugs] [JIRA] (ASTERISK-21409) IAX2 locks up with many threads blocked by iax2_destroy_helper

Alec Davis (JIRA) noreply at issues.asterisk.org
Thu Apr 11 01:24:01 CDT 2013


    [ https://issues.asterisk.org/jira/browse/ASTERISK-21409?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=205195#comment-205195 ] 

Alec Davis edited comment on ASTERISK-21409 at 4/11/13 1:22 AM:
----------------------------------------------------------------

from /var/log/messages:

Mar 2011
[Mar 10 13:09:33] ERROR[10008] /usr/src/pbx/june2009/asterisk-1.6.1/include/asterisk/lock.h: chan_iax2.c line 1547 (iax2_destroy_helper): attempted unlock mutex '&iaxsl[pvt->callno]' without owning it!
[Mar 10 13:09:33] ERROR[10008] /usr/src/pbx/june2009/asterisk-1.6.1/include/asterisk/lock.h: chan_iax2.c line 9464 (socket_process): '&iaxsl[pvt->callno]' was locked here.
[Mar 10 13:09:33] ERROR[10008] /usr/src/pbx/june2009/asterisk-1.6.1/include/asterisk/lock.h: /usr/sbin/asterisk(ast_bt_get_addresses+0x19) [0x81098e0]
[Mar 10 13:09:33] ERROR[10008] /usr/src/pbx/june2009/asterisk-1.6.1/include/asterisk/lock.h: /usr/lib/asterisk/modules/chan_iax2.so [0xb480336c]
[Mar 10 13:09:33] ERROR[10008] /usr/src/pbx/june2009/asterisk-1.6.1/include/asterisk/lock.h: /usr/lib/asterisk/modules/chan_iax2.so [0xb482a498]
[Mar 10 13:09:33] ERROR[10008] /usr/src/pbx/june2009/asterisk-1.6.1/include/asterisk/lock.h: /usr/lib/asterisk/modules/chan_iax2.so [0xb482842c]
[Mar 10 13:09:33] ERROR[10008] /usr/src/pbx/june2009/asterisk-1.6.1/include/asterisk/lock.h: /usr/lib/asterisk/modules/chan_iax2.so [0xb48369f9]
[Mar 10 13:09:33] ERROR[10008] /usr/src/pbx/june2009/asterisk-1.6.1/include/asterisk/lock.h: /usr/sbin/asterisk [0x81825b5]
[Mar 10 13:09:33] ERROR[10008] /usr/src/pbx/june2009/asterisk-1.6.1/include/asterisk/lock.h: /lib/i686/cmov/libpthread.so.0 [0xb7e394c0]
[Mar 10 13:09:33] ERROR[10008] /usr/src/pbx/june2009/asterisk-1.6.1/include/asterisk/lock.h: /lib/i686/cmov/libc.so.6(clone+0x5e) [0xb7f316de]
[Mar 10 13:09:33] ERROR[10008] /usr/src/pbx/june2009/asterisk-1.6.1/include/asterisk/lock.h: chan_iax2.c line 1547 (iax2_destroy_helper): Error releasing mutex: Operation not permitted
[Mar 10 13:09:33] ERROR[10011] /usr/src/pbx/june2009/asterisk-1.6.1/include/asterisk/lock.h: chan_iax2.c line 10844 (socket_process): mutex '&iaxsl[fr->callno]' freed more times than we've locked!

November 2012
[Nov 27 15:42:43] ERROR[22861] lock.c: chan_iax2.c line 1789 (iax2_destroy_helper): attempted unlock mutex '&iaxsl[pvt->callno]' without owning it!
[Nov 27 15:42:43] ERROR[22861] lock.c: chan_iax2.c line 10091 (socket_process): '&iaxsl[pvt->callno]' was locked here.
[Nov 27 15:42:43] ERROR[22861] /usr/src/pbx/jan2011/asterisk-1.8.15.0/include/asterisk/lock.h: /usr/sbin/asterisk(ast_bt_get_addresses+0x19) [0x811c4aa]
[Nov 27 15:42:43] ERROR[22861] /usr/src/pbx/jan2011/asterisk-1.8.15.0/include/asterisk/lock.h: /usr/sbin/asterisk(__ast_pthread_mutex_lock+0xac) [0x8115f6f]
[Nov 27 15:42:43] ERROR[22861] /usr/src/pbx/jan2011/asterisk-1.8.15.0/include/asterisk/lock.h: /usr/lib/asterisk/modules/chan_iax2.so(+0x2ee8d) [0xb6a28e8d]
[Nov 27 15:42:43] ERROR[22861] /usr/src/pbx/jan2011/asterisk-1.8.15.0/include/asterisk/lock.h: /usr/lib/asterisk/modules/chan_iax2.so(+0x2cca6) [0xb6a26ca6]
[Nov 27 15:42:43] ERROR[22861] /usr/src/pbx/jan2011/asterisk-1.8.15.0/include/asterisk/lock.h: /usr/lib/asterisk/modules/chan_iax2.so(+0x3bac8) [0xb6a35ac8]
[Nov 27 15:42:43] ERROR[22861] /usr/src/pbx/jan2011/asterisk-1.8.15.0/include/asterisk/lock.h: /usr/sbin/asterisk() [0x81907c9]
[Nov 27 15:42:43] ERROR[22861] /usr/src/pbx/jan2011/asterisk-1.8.15.0/include/asterisk/lock.h: /lib/i686/cmov/libpthread.so.0(+0x5955) [0xb72f7955]
[Nov 27 15:42:43] ERROR[22861] /usr/src/pbx/jan2011/asterisk-1.8.15.0/include/asterisk/lock.h: /lib/i686/cmov/libc.so.6(clone+0x5e) [0xb75051de]
[Nov 27 15:42:43] ERROR[22856] lock.c: chan_iax2.c line 11514 (socket_process): mutex '&iaxsl[fr->callno]' freed more times than we've locked!
[Nov 27 15:42:43] ERROR[22861] lock.c: chan_iax2.c line 1789 (iax2_destroy_helper): Error releasing mutex: Operation not permitted
[Nov 27 15:43:16] NOTICE[22861] chan_iax2.c: Auto-congesting call due to slow response
[Nov 27 15:43:34] NOTICE[22861] chan_iax2.c: Peer 'auckbdt' is now UNREACHABLE! Time: 11

2013
Weird that the next 2 happened around 10:00, but from what I can determine from CDR logs, an attended transfer was done here;
[Mar  7 10:00:04] ERROR[23577] lock.c: chan_iax2.c line 1791 (iax2_destroy_helper): attempted unlock mutex '&iaxsl[pvt->callno]' without owning it!
[Mar  7 10:00:04] ERROR[23577] lock.c: chan_iax2.c line 10091 (socket_process): '&iaxsl[pvt->callno]' was locked here.
[Mar  7 10:00:04] ERROR[23577] /usr/src/pbx/jan2011/asterisk-1.8.15.0/include/asterisk/lock.h: /usr/sbin/asterisk(ast_bt_get_addresses+0x19) [0x811c4aa]
[Mar  7 10:00:04] ERROR[23577] /usr/src/pbx/jan2011/asterisk-1.8.15.0/include/asterisk/lock.h: /usr/sbin/asterisk(__ast_pthread_mutex_lock+0xac) [0x8115f6f]
[Mar  7 10:00:04] ERROR[23577] /usr/src/pbx/jan2011/asterisk-1.8.15.0/include/asterisk/lock.h: /usr/lib/asterisk/modules/chan_iax2.so(+0x2ee8d) [0xb6a98e8d]
[Mar  7 10:00:04] ERROR[23577] /usr/src/pbx/jan2011/asterisk-1.8.15.0/include/asterisk/lock.h: /usr/lib/asterisk/modules/chan_iax2.so(+0x2cca6) [0xb6a96ca6]
[Mar  7 10:00:04] ERROR[23577] /usr/src/pbx/jan2011/asterisk-1.8.15.0/include/asterisk/lock.h: /usr/lib/asterisk/modules/chan_iax2.so(+0x3bac8) [0xb6aa5ac8]
[Mar  7 10:00:04] ERROR[23577] /usr/src/pbx/jan2011/asterisk-1.8.15.0/include/asterisk/lock.h: /usr/sbin/asterisk() [0x81907c9]
[Mar  7 10:00:04] ERROR[23577] /usr/src/pbx/jan2011/asterisk-1.8.15.0/include/asterisk/lock.h: /lib/i686/cmov/libpthread.so.0(+0x5955) [0xb7366955]
[Mar  7 10:00:04] ERROR[23577] /usr/src/pbx/jan2011/asterisk-1.8.15.0/include/asterisk/lock.h: /lib/i686/cmov/libc.so.6(clone+0x5e) [0xb75741de]
[Mar  7 10:00:04] ERROR[23583] lock.c: chan_iax2.c line 11514 (socket_process): mutex '&iaxsl[fr->callno]' freed more times than we've locked!
[Mar  7 10:00:04] ERROR[23577] lock.c: chan_iax2.c line 1791 (iax2_destroy_helper): Error releasing mutex: Operation not permitted
[Mar  7 10:00:16] NOTICE[23577] chan_iax2.c: Peer 'auckbdt' is now UNREACHABLE! Time: 11

and CDR Event show call was transferred back to orignating site 9 seconds before, I believe a blicd transfer.
[Mar 21 10:00:38] ERROR[26309] lock.c: chan_iax2.c line 1920 (iax2_destroy_helper): attempted unlock mutex '&iaxsl[pvt->callno]' without owning it!
[Mar 21 10:00:38] ERROR[26309] lock.c: chan_iax2.c line 10175 (socket_process_helper): '&iaxsl[pvt->callno]' was locked here.
[Mar 21 10:00:38] ERROR[26309] /usr/src/pbx/jan2011/asterisk-11/include/asterisk/lock.h: /usr/sbin/asterisk(ast_bt_get_addresses+0x19) [0x8139751]
[Mar 21 10:00:38] ERROR[26309] /usr/src/pbx/jan2011/asterisk-11/include/asterisk/lock.h: /usr/sbin/asterisk(__ast_pthread_mutex_lock+0xac) [0x81329c1]
[Mar 21 10:00:38] ERROR[26309] /usr/src/pbx/jan2011/asterisk-11/include/asterisk/lock.h: /usr/lib/asterisk/modules/chan_iax2.so(+0x307df) [0xb68577df]
[Mar 21 10:00:38] ERROR[26309] /usr/src/pbx/jan2011/asterisk-11/include/asterisk/lock.h: /usr/lib/asterisk/modules/chan_iax2.so(+0x3cf55) [0xb6863f55]
[Mar 21 10:00:38] ERROR[26309] /usr/src/pbx/jan2011/asterisk-11/include/asterisk/lock.h: /usr/lib/asterisk/modules/chan_iax2.so(+0x2e605) [0xb6855605]
[Mar 21 10:00:38] ERROR[26309] /usr/src/pbx/jan2011/asterisk-11/include/asterisk/lock.h: /usr/lib/asterisk/modules/chan_iax2.so(+0x3d6c0) [0xb68646c0]
[Mar 21 10:00:38] ERROR[26309] /usr/src/pbx/jan2011/asterisk-11/include/asterisk/lock.h: /usr/sbin/asterisk() [0x81ba1e3]
[Mar 21 10:00:38] ERROR[26309] /usr/src/pbx/jan2011/asterisk-11/include/asterisk/lock.h: /lib/i686/cmov/libpthread.so.0(+0x5955) [0xb72f9955]
[Mar 21 10:00:38] ERROR[26309] /usr/src/pbx/jan2011/asterisk-11/include/asterisk/lock.h: /lib/i686/cmov/libc.so.6(clone+0x5e) [0xb77391de]
[Mar 21 10:00:38] ERROR[26309] lock.c: chan_iax2.c line 1920 (iax2_destroy_helper): Error releasing mutex: Operation not permitted
[Mar 21 10:00:38] ERROR[26317][C-000004a0] lock.c: chan_iax2.c line 11659 (socket_process_helper): mutex '&iaxsl[fr->callno]' freed more times than we've locked!
[Mar 21 10:00:52] NOTICE[26313] chan_iax2.c: Peer 'auckbdt' is now UNREACHABLE! Time: 11


                
      was (Author: alecdavis):
    from /var/log/messages:

[Nov 27 15:42:43] ERROR[22861] lock.c: chan_iax2.c line 1789 (iax2_destroy_helper): attempted unlock mutex '&iaxsl[pvt->callno]' without owning it!
[Nov 27 15:42:43] ERROR[22861] lock.c: chan_iax2.c line 10091 (socket_process): '&iaxsl[pvt->callno]' was locked here.
[Nov 27 15:42:43] ERROR[22861] /usr/src/pbx/jan2011/asterisk-1.8.15.0/include/asterisk/lock.h: /usr/sbin/asterisk(ast_bt_get_addresses+0x19) [0x811c4aa]
[Nov 27 15:42:43] ERROR[22861] /usr/src/pbx/jan2011/asterisk-1.8.15.0/include/asterisk/lock.h: /usr/sbin/asterisk(__ast_pthread_mutex_lock+0xac) [0x8115f6f]
[Nov 27 15:42:43] ERROR[22861] /usr/src/pbx/jan2011/asterisk-1.8.15.0/include/asterisk/lock.h: /usr/lib/asterisk/modules/chan_iax2.so(+0x2ee8d) [0xb6a28e8d]
[Nov 27 15:42:43] ERROR[22861] /usr/src/pbx/jan2011/asterisk-1.8.15.0/include/asterisk/lock.h: /usr/lib/asterisk/modules/chan_iax2.so(+0x2cca6) [0xb6a26ca6]
[Nov 27 15:42:43] ERROR[22861] /usr/src/pbx/jan2011/asterisk-1.8.15.0/include/asterisk/lock.h: /usr/lib/asterisk/modules/chan_iax2.so(+0x3bac8) [0xb6a35ac8]
[Nov 27 15:42:43] ERROR[22861] /usr/src/pbx/jan2011/asterisk-1.8.15.0/include/asterisk/lock.h: /usr/sbin/asterisk() [0x81907c9]
[Nov 27 15:42:43] ERROR[22861] /usr/src/pbx/jan2011/asterisk-1.8.15.0/include/asterisk/lock.h: /lib/i686/cmov/libpthread.so.0(+0x5955) [0xb72f7955]
[Nov 27 15:42:43] ERROR[22861] /usr/src/pbx/jan2011/asterisk-1.8.15.0/include/asterisk/lock.h: /lib/i686/cmov/libc.so.6(clone+0x5e) [0xb75051de]
[Nov 27 15:42:43] ERROR[22856] lock.c: chan_iax2.c line 11514 (socket_process): mutex '&iaxsl[fr->callno]' freed more times than we've locked!
[Nov 27 15:42:43] ERROR[22861] lock.c: chan_iax2.c line 1789 (iax2_destroy_helper): Error releasing mutex: Operation not permitted
[Nov 27 15:43:16] NOTICE[22861] chan_iax2.c: Auto-congesting call due to slow response
[Nov 27 15:43:34] NOTICE[22861] chan_iax2.c: Peer 'auckbdt' is now UNREACHABLE! Time: 11

Weird that the next 2 happened around 10:00, but from what I can determine from CDR logs, an attended transfer was done here;
[Mar  7 10:00:04] ERROR[23577] lock.c: chan_iax2.c line 1791 (iax2_destroy_helper): attempted unlock mutex '&iaxsl[pvt->callno]' without owning it!
[Mar  7 10:00:04] ERROR[23577] lock.c: chan_iax2.c line 10091 (socket_process): '&iaxsl[pvt->callno]' was locked here.
[Mar  7 10:00:04] ERROR[23577] /usr/src/pbx/jan2011/asterisk-1.8.15.0/include/asterisk/lock.h: /usr/sbin/asterisk(ast_bt_get_addresses+0x19) [0x811c4aa]
[Mar  7 10:00:04] ERROR[23577] /usr/src/pbx/jan2011/asterisk-1.8.15.0/include/asterisk/lock.h: /usr/sbin/asterisk(__ast_pthread_mutex_lock+0xac) [0x8115f6f]
[Mar  7 10:00:04] ERROR[23577] /usr/src/pbx/jan2011/asterisk-1.8.15.0/include/asterisk/lock.h: /usr/lib/asterisk/modules/chan_iax2.so(+0x2ee8d) [0xb6a98e8d]
[Mar  7 10:00:04] ERROR[23577] /usr/src/pbx/jan2011/asterisk-1.8.15.0/include/asterisk/lock.h: /usr/lib/asterisk/modules/chan_iax2.so(+0x2cca6) [0xb6a96ca6]
[Mar  7 10:00:04] ERROR[23577] /usr/src/pbx/jan2011/asterisk-1.8.15.0/include/asterisk/lock.h: /usr/lib/asterisk/modules/chan_iax2.so(+0x3bac8) [0xb6aa5ac8]
[Mar  7 10:00:04] ERROR[23577] /usr/src/pbx/jan2011/asterisk-1.8.15.0/include/asterisk/lock.h: /usr/sbin/asterisk() [0x81907c9]
[Mar  7 10:00:04] ERROR[23577] /usr/src/pbx/jan2011/asterisk-1.8.15.0/include/asterisk/lock.h: /lib/i686/cmov/libpthread.so.0(+0x5955) [0xb7366955]
[Mar  7 10:00:04] ERROR[23577] /usr/src/pbx/jan2011/asterisk-1.8.15.0/include/asterisk/lock.h: /lib/i686/cmov/libc.so.6(clone+0x5e) [0xb75741de]
[Mar  7 10:00:04] ERROR[23583] lock.c: chan_iax2.c line 11514 (socket_process): mutex '&iaxsl[fr->callno]' freed more times than we've locked!
[Mar  7 10:00:04] ERROR[23577] lock.c: chan_iax2.c line 1791 (iax2_destroy_helper): Error releasing mutex: Operation not permitted
[Mar  7 10:00:16] NOTICE[23577] chan_iax2.c: Peer 'auckbdt' is now UNREACHABLE! Time: 11

and CDR Event show call was transferred back to orignating site 9 seconds before, I believe a blicd transfer.
[Mar 21 10:00:38] ERROR[26309] lock.c: chan_iax2.c line 1920 (iax2_destroy_helper): attempted unlock mutex '&iaxsl[pvt->callno]' without owning it!
[Mar 21 10:00:38] ERROR[26309] lock.c: chan_iax2.c line 10175 (socket_process_helper): '&iaxsl[pvt->callno]' was locked here.
[Mar 21 10:00:38] ERROR[26309] /usr/src/pbx/jan2011/asterisk-11/include/asterisk/lock.h: /usr/sbin/asterisk(ast_bt_get_addresses+0x19) [0x8139751]
[Mar 21 10:00:38] ERROR[26309] /usr/src/pbx/jan2011/asterisk-11/include/asterisk/lock.h: /usr/sbin/asterisk(__ast_pthread_mutex_lock+0xac) [0x81329c1]
[Mar 21 10:00:38] ERROR[26309] /usr/src/pbx/jan2011/asterisk-11/include/asterisk/lock.h: /usr/lib/asterisk/modules/chan_iax2.so(+0x307df) [0xb68577df]
[Mar 21 10:00:38] ERROR[26309] /usr/src/pbx/jan2011/asterisk-11/include/asterisk/lock.h: /usr/lib/asterisk/modules/chan_iax2.so(+0x3cf55) [0xb6863f55]
[Mar 21 10:00:38] ERROR[26309] /usr/src/pbx/jan2011/asterisk-11/include/asterisk/lock.h: /usr/lib/asterisk/modules/chan_iax2.so(+0x2e605) [0xb6855605]
[Mar 21 10:00:38] ERROR[26309] /usr/src/pbx/jan2011/asterisk-11/include/asterisk/lock.h: /usr/lib/asterisk/modules/chan_iax2.so(+0x3d6c0) [0xb68646c0]
[Mar 21 10:00:38] ERROR[26309] /usr/src/pbx/jan2011/asterisk-11/include/asterisk/lock.h: /usr/sbin/asterisk() [0x81ba1e3]
[Mar 21 10:00:38] ERROR[26309] /usr/src/pbx/jan2011/asterisk-11/include/asterisk/lock.h: /lib/i686/cmov/libpthread.so.0(+0x5955) [0xb72f9955]
[Mar 21 10:00:38] ERROR[26309] /usr/src/pbx/jan2011/asterisk-11/include/asterisk/lock.h: /lib/i686/cmov/libc.so.6(clone+0x5e) [0xb77391de]
[Mar 21 10:00:38] ERROR[26309] lock.c: chan_iax2.c line 1920 (iax2_destroy_helper): Error releasing mutex: Operation not permitted
[Mar 21 10:00:38] ERROR[26317][C-000004a0] lock.c: chan_iax2.c line 11659 (socket_process_helper): mutex '&iaxsl[fr->callno]' freed more times than we've locked!
[Mar 21 10:00:52] NOTICE[26313] chan_iax2.c: Peer 'auckbdt' is now UNREACHABLE! Time: 11


                  
> IAX2 locks up with many threads blocked by iax2_destroy_helper
> --------------------------------------------------------------
>
>                 Key: ASTERISK-21409
>                 URL: https://issues.asterisk.org/jira/browse/ASTERISK-21409
>             Project: Asterisk
>          Issue Type: Bug
>      Security Level: None
>          Components: Channels/chan_iax2
>    Affects Versions: 1.8.15.0, 11.3.0
>         Environment: Debian Squeeze
>            Reporter: Alec Davis
>         Attachments: iax-lock-asterisk-11.txt, iax-lock-asterisk-1-8-15.txt
>
>
> Intermittently all IAX calls stop over the trunk.
> I think this is reproduced when a call is transferred back to the originating site, we have "transfer=on"
> Also happened with asterisk SVN-branch-11-r382514.
> Attached are the 1.8.15.0 lockup, and the 11-branch lockup.
>  

--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators: https://issues.asterisk.org/jira/secure/ContactAdministrators!default.jspa
For more information on JIRA, see: http://www.atlassian.com/software/jira



More information about the asterisk-bugs mailing list