[asterisk-bugs] [JIRA] (ASTERISK-27140) Memory leak in sorcery.c – pjsip subcribtions not expired

Jacek Konieczny (JIRA) noreply at issues.asterisk.org
Fri Jul 28 07:40:00 CDT 2017


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

Jacek Konieczny commented on ASTERISK-27140:
--------------------------------------------

I was able to reproduce the problem on a vanilla Asterisk 14.6 with a simple config.

Once I got dozens of duplicate stale subscriptions overnight. Now, after a restart I have only one non-expiring duplicate.

I am trying to prepare a simple reproducible test case, but I still have no idea what is the trigger. A bug is definitely there in the Asterisk code.

> Memory leak in sorcery.c – pjsip subcribtions not expired
> ---------------------------------------------------------
>
>                 Key: ASTERISK-27140
>                 URL: https://issues.asterisk.org/jira/browse/ASTERISK-27140
>             Project: Asterisk
>          Issue Type: Bug
>      Security Level: None
>    Affects Versions: 13.15.1, 14.6.0
>         Environment: Linux 4.4.66, 32-bit asterisk
> Yealink T41, T23, T27  and Snom 710 SIP phones
>            Reporter: Jacek Konieczny
>            Assignee: Jacek Konieczny
>
> We have experienced quite a serious memory leak on a system running Asterisk 13.14.1. Asterisk process would grow until it fails due to OOM problems.
> We have enabled memory debugging code in Asterisk, which pointed us to allocation in the 'sorcery.c' file. Here are some of regular measurements:
> {noformat}
> Jul 18 08:29:05  12293024 bytes in       1871 allocations in file sorcery.c
> Jul 18 08:30:05  12427300 bytes in       1879 allocations in file sorcery.c
> Jul 18 08:31:05  12494666 bytes in       1885 allocations in file sorcery.c
> Jul 18 08:32:05  12662739 bytes in       1897 allocations in file sorcery.c
> [...]
> Jul 18 13:08:05  53012221 bytes in       4297 allocations in file sorcery.c
> Jul 18 13:09:05  53146497 bytes in       4305 allocations in file sorcery.c
> Jul 18 13:10:05  53246976 bytes in       4309 allocations in file sorcery.c
> {noformat}
> Further investigation lead us to the abnormal count of pjsip subscriptions:
> {noformat}
> CLI> pjsip show subscriptions inbound
> Endpoint: <Endpoint/Caller-ID.............................................>
> Resource: <Resource/Event.................................................>
>   Expiry: <Expiry>  <Call-id..............................................>
> ===========================================================================
> Endpoint: pauu9/"phone:pauu9" <phone_pauu9>
> Resource: 603/dialog
>   Expiry:        0  0_3532174332 at X.X.X.X
> Endpoint: 8wmgf/"phone:8wmgf" <phone_8wmgf>
> Resource: 603/dialog
>   Expiry:        0  0_1381764142 at X.X.X.X
> [...]
> Endpoint: waqiy/"phone:waqiy" <phone_waqiy>
> Resource: 400/dialog
>   Expiry:     1748  0_710460239 at X.X.X.X
> 1603 active subscriptions
> {noformat}
> We have seen even over 10000 active subscriptions there. Most of them with 'Expiry: 0' (similar to ASTERISK-26821).
> The system would also occasionally crash due to ASTERISK-27057, so I hoped Asterisk upgrade will fix the problem.
> Unfortunately, we are able to reproduce the memory/subscription leak on Asterisk 14.6.0 in our test system. It is not that dramatic there, though, as the system load is much lower.
> {noformat}
> qemu*CLI> pjsip show subscriptions inbound
> Endpoint: <Endpoint/Caller-ID.............................................>
> Resource: <Resource/Event.................................................>
>   Expiry: <Expiry>  <Call-id..............................................>
> ===========================================================================
> Endpoint: vfd5v/"phone:vfd5v" <phone_vfd5v>
> Resource: 313/dialog
>   Expiry:        0  0_3957488405 at 192.168.1.141
> Endpoint: rcumw/"phone:rcumw" <phone_rcumw>
> Resource: rcumw/message-summary
>   Expiry:     2228  0_3402140230 at 192.168.1.100
> Endpoint: rcumw/"phone:rcumw" <phone_rcumw>
> Resource: 555/dialog
>   Expiry:        0  0_2653972870 at 192.168.1.100
> Endpoint: rcumw/"phone:rcumw" <phone_rcumw>
> Resource: 327/dialog
>   Expiry:        0  0_3105449958 at 192.168.1.100
> Endpoint: rcumw/"phone:rcumw" <phone_rcumw>
> Resource: 307/dialog
>   Expiry:        0  0_3959991489 at 192.168.1.100
> Endpoint: rcumw/"phone:rcumw" <phone_rcumw>
> Resource: 313/dialog
>   Expiry:        0  0_3788627546 at 192.168.1.100
> Endpoint: rcumw/"phone:rcumw" <phone_rcumw>
> Resource: 400/dialog
>   Expiry:        0  0_2717320225 at 192.168.1.100
> [...]
> Endpoint: rcumw/"phone:rcumw" <phone_rcumw>
> Resource: 400/dialog
>   Expiry:     1786  0_1665913924 at 192.168.1.100
> 185 active subscriptions
> {noformat}
> This took just ~3 hours.
> This test system has only 20 endpoints and only couple of them use SIP subscription to couple of others. Most entries on the list are duplicates, with 'Expiry: 0'.
> {{sorcery.c}} allocations were also increasing:
> {noformat}
>    2569589 bytes in        857 allocations in file sorcery.c
> [...]
>    5994851 bytes in       1061 allocations in file sorcery.c
> {noformat}
> Step to reproduce:
> * Set up Asterisk PBX with a few SIP phones
> * Configure BLF on the sip phones to SIP-subscribe other endpoints
> * Have some of the subscribed extensions unavailable (assigned SIP phones offline)
> * wait until first entries are to be expired (Expiry: 0  in 'pjsip show subscriptions inbound')
> Expected results: expired entries disappear after some time.
> Actual result: expired entries stay in the 'pjsip show subscriptions inbound'
> Note: we have reproduced it only in our specific Asterisk configuration, as we have no means to quickly reproduce it in and isolated simple Asterisk setup (our test systems are designed to test our product, not Asterisk alone).
> I guess the way we use hints in asterisk dial plan may be related to the problem, so here is a sample:
> {noformat}
> [ext-local]
> exten => 303,hint,${HINT(1581dca5-e34d-371c-aed0-09002af06d06 at users)}
> exten => 313,hint,${HINT(56d1d500-09dd-34ec-b40a-d65c065a186e at users)}
> exten => 330,hint,${HINT(a4f5591b-78f2-3d9c-980e-4d6fa097b924 at users)}
> exten => 300,hint,PJSIP/ooz9t
> ...
> [users]
> exten => 56d1d500-09dd-34ec-b40a-d65c065a186e,hint,PJSIP/jfikn&custom:313,CustomPresence:313
> exten => 1581dca5-e34d-371c-aed0-09002af06d06,hint,PJSIP/rcumw&custom:401,CustomPresence:401
> exten => c3d62505-11dc-36db-9aa3-508693b6a3c0,hint,PJSIP/fgd6r,CustomPresence:327
> ...
> {noformat}
> We may attempt to gather more debugging information next week, if needed,



--
This message was sent by Atlassian JIRA
(v6.2#6252)



More information about the asterisk-bugs mailing list