[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