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

[Jacek Konieczny (JIRA)]

Jacek Konieczny created ASTERISK-27140:
------------------------------------------

             Summary: 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: 14.6.0, 13.15.1
         Environment: Linux 4.4.66, 32-bit asterisk
Yealink T41, T23, T27  and Snom 710 SIP phones
            Reporter: 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 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 endpoints inbound')

Expected results: expired entries disappear after some time.
Actual result: expired entries stay in the 'pjsip show endpoints 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)