[Home]

Summary:ASTERISK-24916: Increasing memory usage when multiple reinvite during call
Reporter:Christophe Osuna (coa001)Labels:
Date Opened:2015-03-26 09:36:35Date Closed:2015-04-29 14:15:08
Priority:MajorRegression?
Status:Closed/CompleteComponents:Channels/chan_sip/General
Versions:11.16.0 Frequency of
Occurrence		Constant
Related
Issues:
Environment:Attachments:( 0) asterisk.log
( 1) mem_atexit.log
( 2) mem0.log
( 3) mem1.log
( 4) mem2.log
( 5) reinvite_loop.pl
( 6) rtp_engine0.log
( 7) rtp_engine1.log
( 8) rtp_engine2.log
Description:We have a setup with an Asterisk server 11.16.0 and an equipment sending periodically SIP INVITE requests during the same call. When monitoring memory usage, we noticed that RSS memory of the Asterisk process keeps on increasing. It's not a huge amount, but it's non-zero, so at some point this will trigger the OOM reaper and Asterisk process will be killed.

The bug will happen in the following conditions:
* in sip.conf ignoresdpversion is set and UA sends periodically SIP re-INVITE;
* ignoredspversion is not set, and UA sends periodically SIP re-INVITE with a SDP session information with an increasing session version.

I am attaching to the issue a Perl script to reproduce the issue.

We used the DONT_OPTIMZE and MALLOC_DEBUG options to track down the issue. When monitoring the output of the 'memory show summary' command we can see that allocation increases for the file rtp_engine.c. Then, the output of 'memory show allocations rtp_engine.c' shows allocations in function rtp_engine.c:ast_rtp_codecs_payloads_copy(). So, my understanding of the issue is that whenever a SIP INVITE is received, the function chan_sip.c:process_sdp() is called. If the subsequent call to process_sdp_o() indicates that the session has been modified, the code will allocate new resources in ast_rtp_codecs_payloads_copy(), but will not necessarily free previously used resources.
Comments:By: Rusty Newton (rnewton) 2015-03-26 18:20:05.540-0500

Thanks for the script. Can you attach the MALLOC_DEBUG output as well?
By: Rusty Newton (rnewton) 2015-03-26 18:20:23.889-0500

Remember to hit Send Back or Enter Feedback to send the issue back to us.
By: Christophe Osuna (coa001) 2015-03-27 07:01:27.562-0500

= Attachments =

Perl script to reproduce the issue:
* reinvite_loop.pl

Output of 'memory show summary'
* mem0.log: initial value
* mem1.log: during the re-invite loop
* mem2.log: later during the loop

I experienced that monitoring the output in real time shows better the increase. Interesting part from the diff between mem1.log and mem2.log:
 -    855960 bytes in      35665 allocations in file astobj2.c
 +    903792 bytes in      37658 allocations in file astobj2.c
 -    833512 bytes in       2234 allocations in file rtp_engine.c
 +   1566184 bytes in       4223 allocations in file rtp_engine.c
(but there are other differences that you may find more relevant)

Output of 'memory show allocations rtp_engine.c':
* rtp_engine0.log: initial value
* rtp_engine1.log: during the re-INVITE loop
* rtp_engine2.log: later during the loop

Actually that last log is only interesting to see the allocations increasing during the re-INVITE loop:
 +       364 bytes allocated by ast_rtp_codecs_payloads_copy() line   511 of rtp_engine.c
(repeated 2,000 times)

Memory usage at exit:
* mem_atexit.log: memory usage by file after shutting down process with 'core stop gracefully'

Asterisk log:
* asterisk.log: console output from 'asterisk -f -d -vvvv'

By: Christophe Osuna (coa001) 2015-03-27 07:05:11.116-0500

Added attachments with some log output from MALLOC_DEBUG.

By: Flomont L (flomontl) 2015-03-31 10:02:01.574-0500

Do you have potential solutions for our issue?
By: Mark Michelson (mmichelson) 2015-04-29 11:57:47.582-0500

A proposed fix for this is currently under review at https://gerrit.asterisk.org/#/c/291/

When the patch is merged, this issue will be closed.