[Home]

Summary:ASTERISK-28564: Memory leak with pjsip 2.9 and SIPS / SRTP
Reporter:Michael Maier (micha)Labels:fax pjsip
Date Opened:2019-10-03 08:59:22Date Closed:2019-11-14 13:55:29.000-0600
Priority:MinorRegression?Yes
Status:Closed/CompleteComponents:Channels/chan_pjsip
Versions:16.5.0 Frequency of
Occurrence
Constant
Related
Issues:
Environment:CentOS 7Attachments:
Description:There is one more memory leak even in asterisk 16.6.0-rc2, which can't be seen with pjsip 2.8 instead of 2.9. It can be seen on inbound calls (not sure if it's on outbound calls, too) using SIPS and SRTP.

Examples:
1 Call, duration about 1 h: ~ +1,2 MB
5 short calls (< 1 minute): ~ +1 MB


Example for the inbound INVITE and OK package:

<--- Received SIP request (2276 bytes) from TLS:217.0.20.195:5061 --->
INVITE sip:+491234567890@12.13.14.15:5061;transport=tcp;line=abcdefg SIP/2.0
Max-Forwards: 49
Via: SIP/2.0/TLS 217.0.20.195:5061;branch=z9hG4bKg3Zqkv7ivdsp3wo1jhdbdvgy5dwsq6jye
To: <sip:+491234567890@telekom.de;user=phone>
From: <sip:+4945678901234@tmobile.de;user=phone>;tag=h7g4Esbg_p65540t1570108521m378032c299263169s1_1621954413-1461120854
Call-ID: p65540t1570108521m378032c299263169s2
CSeq: 1 INVITE
Contact: <sip:sgc_c@217.0.20.195:5061;transport=tls>;+g.3gpp.icsi-ref="urn%3Aurn-7%3A3gpp-service.ims.icsi.mmtel"
Record-Route: <sip:217.0.20.195:5061;transport=tls;lr>
Accept-Contact: *;+g.3gpp.icsi-ref="urn%3Aurn-7%3A3gpp-service.ims.icsi.mmtel"
History-Info: <sip:+491234567890;npdi;rn=+49199C901234567890@tmobile.de;user=phone>;index=1
Min-Se: 900
P-Asserted-Identity: <sip:+4945678901234@tmobile.de;user=phone>
P-Asserted-Identity: <tel:+4945678901234>
Session-Expires: 1800
Supported: timer
Supported: 100rel
Supported: histinfo
Supported: 199
Supported: uui
Supported: norefersub
Content-Type: application/sdp
Content-Length: 1061
Session-ID: 253f41678c65f936805ef6b071943e64
Allow: REGISTER, REFER, NOTIFY, SUBSCRIBE, UPDATE, PRACK, INFO, INVITE, ACK, OPTIONS, CANCEL, BYE

v=0
o=- 1011696818 1621954173 IN IP4 217.0.20.195
s=-
c=IN IP4 217.0.135.5
t=0 0
m=audio 27888 RTP/SAVP 96 97 9 98 99 100 101 8 102 103
b=AS:84
a=rtpmap:96 AMR-WB/16000
a=fmtp:96 mode-set=0,1,2; mode-change-period=2; mode-change-neighbor=1; max-red=0
a=rtpmap:97 AMR-WB/16000
a=fmtp:97 mode-change-capability=2; max-red=0
a=rtpmap:9 G722/8000
a=rtpmap:98 AMR/8000
a=fmtp:98 mode-set=0,2,4,7; mode-change-period=2; mode-change-neighbor=1; max-red=0
a=rtpmap:99 AMR/8000
a=fmtp:99 mode-set=0,2,4; mode-change-period=2; mode-change-neighbor=1; max-red=0
a=rtpmap:100 AMR/8000
a=fmtp:100 mode-set=0,1,2,3,4,5,6,7; mode-change-period=2; mode-change-neighbor=1; max-red=0
a=rtpmap:101 AMR/8000
a=fmtp:101 mode-set=0,1,2,3,4,5,6,7; max-red=0
a=rtpmap:8 PCMA/8000
a=rtpmap:102 telephone-event/8000
a=rtpmap:103 telephone-event/16000
a=ptime:20
a=maxptime:30
a=3ge2ae:applied
a=crypto:1 AES_CM_128_HMAC_SHA1_80 inline:HTNhK8lOYS+/1ORuNEbEhnsisXj4PEVIh8FBKmTR
a=crypto:2 AES_CM_128_HMAC_SHA1_32 inline:6qBJEfKKXxbpJTepS298yUmUl/891GwnlURC3tdn




<--- Transmitting SIP response (1178 bytes) to TLS:217.0.20.195:5061 --->
SIP/2.0 200 OK
Via: SIP/2.0/TLS 217.0.20.195:5061;rport=5061;received=217.0.20.195;branch=z9hG4bKg3Zqkv7ivdsp3wo1jhdbdvgy5dwsq6jye
Record-Route: <sip:217.0.20.195:5061;transport=TLS;lr>
Call-ID: p65540t1570108521m378032c299263169s2
From: <sip:+4945678901234@tmobile.de;user=phone>;tag=h7g4Esbg_p65540t1570108521m378032c299263169s1_1621954413-1461120854
To: <sip:+491234567890@telekom.de;user=phone>;tag=94f22858-9c32-44c5-8a45-76964f62684a
CSeq: 1 INVITE
Server: FPBX-14.0.11(16.5.1)
Allow: OPTIONS, REGISTER, SUBSCRIBE, NOTIFY, PUBLISH, INVITE, ACK, BYE, CANCEL, UPDATE, PRACK, MESSAGE, REFER
Contact: <sip:12.13.14.15:5061;transport=TLS>
Supported: 100rel, timer, replaces, norefersub
Session-Expires: 1800;refresher=uac
Require: timer
Content-Type: application/sdp
Content-Length:   368

v=0
o=- 1011696818 1621954176 IN IP4 12.13.14.15
s=Asterisk
c=IN IP4 12.13.14.15
t=0 0
m=audio 10032 RTP/SAVP 9 8 102
a=3ge2ae:requested
a=crypto:1 AES_CM_128_HMAC_SHA1_80 inline:OnkHAdHasSl83UnyFNuDSrBx+OsRF8DRZ6c5PnmJ
a=rtpmap:9 G722/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:102 telephone-event/8000
a=fmtp:102 0-16
a=ptime:20
a=maxptime:150
a=sendrecv
Comments:By: Asterisk Team (asteriskteam) 2019-10-03 08:59:22.982-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].

Please note that once your issue enters an open state it has been accepted. As Asterisk is an open source project there is no guarantee or timeframe on when your issue will be looked into. If you need expedient resolution you will need to find and pay a suitable developer. Asking for an update on your issue will not yield any progress on it and will not result in a response. All updates are posted to the issue when they occur.

By: Sean Bright (seanbright) 2019-10-03 09:05:12.204-0500

Please provide a configuration that exhibits this.

By: Michael Maier (micha) 2019-10-03 09:13:58.119-0500

Don't know, if it's relevant, but the internal client is connected to asterisk using SIP / UDP.

About the configuration:
I can't believe that you don't know how to configure SRTP / TLS for an extension on asterisk. Sorry.

By: Joshua C. Colp (jcolp) 2019-10-03 09:17:46.624-0500

[~micha] [~seanbright] is aware of SRTP / TLS configuration but we've found that in general having a specific configuration reduces the amount of time wasted on trying to track things down due to differences, so it's standard practice to ask for such things. I once spent over a week trying to find a problem waiting for a reporter to respond, once they did and provided their configuration I was able to track it down in minutes. That's why we treat it as standard practice. You are certainly free not to provide it and we still attempt to isolate and identify problems.

By: Michael Maier (micha) 2019-10-03 09:37:42.683-0500

There is no specific configuration I would be aware of. Just configure SRTP / SIPS / TLS 1.2 and you should get the problem.

{noformat}
pjsip.registration.conf
---------------------------------
[trunk]
type=registration
transport=0.0.0.0-tls
outbound_auth=trunk
retry_interval=60
fatal_retry_interval=0
forbidden_retry_interval=10
max_retries=10000
expiration=660
line=yes
endpoint=trunk
auth_rejection_permanent=yes
contact_user=+49123456789
server_uri=sip:tel.t-online.de
client_uri=sip:+49123456789@tel.t-online.de


pjsip.transports_custom.conf
------------------------------------------
[0.0.0.0-udp]
type=transport
protocol=udp
bind=0.0.0.0:5061
allow_reload=no
tos=cs3
cos=3

[0.0.0.0-tls]
type=transport
protocol=tls
bind=0.0.0.0:5061
ca_list_file=/etc/pki/tls/certs/ca-bundle.crt
method=tlsv1_2
verify_server=yes
allow_reload=no
tos=cs3
cos=3

pjsip.transports_custom_post.conf
--------------------------------------------------
[0.0.0.0-udp](+)
tos=0xb8

[0.0.0.0-tls](+)
method=tlsv1_2
tos=0xb8


pjsip.auth_custom.conf
----------------------------------
[trunk]
type=auth
auth_type=userpass
password=12345
username=+49123456789

pjsip.identify_custom.conf
--------------------------------------
[trunk]
type=identify
endpoint=trunk
match=127.0.0.10

pjsip.endpoint.conf
----------------------------
[trunk]
type=endpoint
transport=0.0.0.0-tls
context=from-pstn
disallow=all
allow=alaw,ulaw
aors=trunk
language=de
outbound_auth=trunk
from_domain=tel.t-online.de
from_user=+49123456789
t38_udptl=no
t38_udptl_ec=none
fax_detect=no
trust_id_inbound=no
t38_udptl_nat=no
direct_media=no
rewrite_contact=yes
media_encryption=sdes
rtp_symmetric=yes
dtmf_mode=rfc4733

pjsip.endpoint_custom_post.conf
------------------------------------------------
[trunk](+)
tos_audio=0xb8
rtp_timeout=120
{noformat}

Hope this is enough or do you need some more information?
If you can't reproduce it, we have to rethink about how to proceed.

-> Just added the endpoint conf, which was missing (I forgot it).

By: Joshua C. Colp (jcolp) 2019-10-07 12:36:00.221-0500

I've begun looking into this and so far have not been able to produce the same result. Using TLS and SRTP from a phone I've placed numerous small length calls (under 1 minute, as well as ones longer) but memory usage has remained constant and has not grown as described.

By: Michael Maier (micha) 2019-10-07 14:43:41.982-0500

I measured it on base of of ps aux / RSS. I can't see any growth on RSS using pjsip 2.8, but 2.9 (same asterisk version 16.5.1 e.g.).
Maybe packet sizes are different? The udp packet size here is 226 bytes (length as shown by wireshark) and data length is 182 bytes.

Unfortunately, I'm not able to do any further investigation at the moment. Maybe next weekend (but not sure).
Please don't spend unnecessary time on it as long as you don't have any clever idea by chance.
Is there something like git bisect for the pjsip code? Maybe I can find the culprit this way? Would be more easily I think.

By: Sean Bright (seanbright) 2019-10-07 15:50:28.183-0500

You could try svn bisect between [this|http://svn.pjsip.org/repos/pjproject/tags/2.8/] and [this|http://svn.pjsip.org/repos/pjproject/tags/2.9/].

By: Joshua C. Colp (jcolp) 2019-10-09 09:06:29.159-0500

Assigning to you for feedback per previous comments.

By: Michael Maier (micha) 2019-10-12 09:46:21.086-0500

I'm testing at the moment on base of asterisk 16.6.0 and pjsip 2.9 with two more additional patches:
https://trac.pjsip.org/repos/changeset/6089
https://github.com/pjsip/pjproject/commit/ed08f5bbcb7ef51d6798d0fcbea3f65f85c88261

At the moment, I can't see the problem any more. But maybe it's related too to the point of starting the measurement. I started on base of an already high memory usage basis (> 82 MB RSS), which can be reached easily after a few core reloads. Let's wait and see.

By: Michael Maier (micha) 2019-10-20 13:25:35.277-0500

The problem is tricky - most of the time, it works as it should, but in two cases e.g. I could see a mysterious rise of 1.1 MB during one hour (there was a call ongoing during those hours - but that can't be seen always). At the moment, the memory usage is 89 MByte. That's ok for my use case. Anyway, the reason for the sudden rises of the memory usage would be interesting.
Another reason for repeatedly (but not always) rising memory usage is sending or receiving of faxes (spandsp).
Maybe that's expected behavior? I can't say. If you want, you may close this ticket.

By: Joshua C. Colp (jcolp) 2019-11-14 13:55:29.845-0600

Per your comment I'm suspending since we weren't able to reproduce it and it doesn't seem to be a problem for you.