sipp v3.4.1 memory leak issue

[gomting30]

When we started ipv6 load test with sipp v3.4.1, there was critical memory leak issue at UAS side. sipp process only is using up more than gigabyte of memory. I don't know what is the problem. it might be the problem of sipp v3.4.1 itself or UAS scenario problemn but i am not sure.

1. uac command line:

   ../sipp -r 300 -rp 1000 -inf usr.csv -sf uac.xml \
     -i [fd00:0:0:7ea1:10:1:1:80] -trace_err [fd00:0:0:7ea1:10:1:1:91]:5060
   

2. uas command line:

   ../sipp -sn uas -trace_err -sf mrf.xml -p 5010 \
     -i [fd00:0:0:7ea1:10:1:1:80]
   

3. usr.csv file

   RANDOM,PRINTF=300
   01088880%03d;01099990%03d
   

4.uas scenario file

<?xml version="1.0" encoding="ISO-8859-1" ?>
<!DOCTYPE scenario SYSTEM "sipp.dtd">

<!-- This program is free software; you can redistribute it and/or      -->
<!-- modify it under the terms of the GNU General Public License as     -->
<!-- published by the Free Software Foundation; either version 2 of the -->
<!-- License, or (at your option) any later version.                    -->
<!--                                                                    -->
<!-- This program is distributed in the hope that it will be useful,    -->
<!-- but WITHOUT ANY WARRANTY; without even the implied warranty of     -->
<!-- MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the      -->
<!-- GNU General Public License for more details.                       -->
<!--                                                                    -->
<!-- You should have received a copy of the GNU General Public License  -->
<!-- along with this program; if not, write to the                      -->
<!-- Free Software Foundation, Inc.,                                    -->
<!-- 59 Temple Place, Suite 330, Boston, MA  02111-1307 USA             -->
<!--                                                                    -->
<!--                 Sipp default 'uas' scenario.                       -->
<!--                                                                    -->

<scenario name="uas_ct">
  <!-- By adding rrs="true" (Record Route Sets), the route sets         -->
  <!-- are saved and used for following messages sent. Useful to test   -->
  <!-- against stateful SIP proxies/B2BUAs.                             -->
  <recv request="INVITE">
    <!--action>
        <ereg regexp=".*" occurrence="1" search_in="hdr" header="Via:" assign_to="1"/>
        <ereg regexp=".*" search_in="hdr" header="From:" check_it="true" assign_to="2"/>
        <ereg regexp=".*" search_in="hdr" header="To:" check_it="true" assign_to="3"/>
    </action-->
<!--
          <action>
                  <ereg regexp=".*" search_in="hdr" header="From:" check_it="true" assign_to="1"/>
                  <ereg regexp=".*" search_in="hdr" header="To:" check_it="true" assign_to="2"/>
                  <ereg regexp="sip:([0-9A-Za-z\.]+):([0-9]+);transport=([a-z]+)" search_in="hdr" header="Contact:" check_it="true" assign_to="3,4,5,6"/>
                  <log message="FROM:[$1]"/>
                  <log message="TO:[$2]"/>
                  <log message="CONTACT:[$3]"/>
                  <log message="CONTACT:[$4]"/>
                  <log message="CONTACT:[$5]"/>
                  <log message="CONTACT:[$6]"/>
          </action>
-->
  </recv>

  <!-- The '[last_*]' keyword is replaced automatically by the          -->
  <!-- specified header if it was present in the last message received  -->
  <!-- (except if it was a retransmission). If the header was not       -->
  <!-- present or if no message has been received, the '[last_*]'       -->
  <!-- keyword is discarded, and all bytes until the end of the line    -->
  <!-- are also discarded.                                              -->
  <!--                                                                  -->
  <!-- If the specified header was present several times in the         -->
  <!-- message, all occurences are concatenated (CRLF seperated)        -->
  <!-- to be used in place of the '[last_*]' keyword.                   -->

  <!-- pause milliseconds="15000"/ -->


  <send>
    <![CDATA[

      SIP/2.0 100 Trying
      [last_Via:]
      [last_From:]
      [last_To:];tag=1234567890_[call_number]
      [last_Call-ID:]
      [last_CSeq:]
      Content-Length: 0

    ]]>
  </send>

  <!--pause milliseconds="5000"/-->

   <!--send retrans="500"-->
   <send>
    <![CDATA[

      SIP/2.0 200 OK
      [last_Via:]
      [last_From:]
      [last_To:];tag=1234567890_[call_number]
      [last_Call-ID:]
      [last_CSeq:]
      Allow: INVITE, ACK, BYE, OPTIONS, CANCEL, INFO, PRACK, UPDATE
      Accept: application/sdp, text/*, application/msml+xml, application/moml+xml
      Contact: <sip:msml@[local_ip]:[local_port];transport=[transport]>
      Content-Length: [len]
      Content-Type: application/sdp

      v=0
      o=user1 53655765 2353687637 IN IP[local_ip_type] [local_ip]
      s=-
      c=IN IP[media_ip_type] [media_ip]
      t=0 0
      m=audio [media_port] RTP/AVP 0 96
      a=rtpmap:0 PCMU/8000
      a=rtpmap:96 telephone-event/8000
      a=fmtp:96 0-15,32,36
      a=sendrecv
    ]]>
  </send>

  <recv request="ACK"
        optional="true"
        crlf="true">
  </recv>

  <recv request="INFO">
  </recv>

  <send crlf="true">
    <![CDATA[

      SIP/2.0 200 OK
      [last_Via:]
      [last_From:]
      [last_To:]
      [last_Call-ID:]
      [last_CSeq:]
      Accept: application/sdp, text/*, application/msml+xml, application/moml+xml
      Contact: <sip:msml@[local_ip]:[local_port];transport=[transport]>
      Content-Length: [len]
      Content-Type: application/msml+xml

      <?xml version="1.0" encoding="US-ASCII"?>
      <msml version="1.1">
              <result response="200">
              </result>
      </msml>
    ]]>
  </send>

  <!--send retrans="500">
  <![CDATA[
  BYE sip:[email protected]:5071 SIP/2.0
  Via: [$1]
  From: [$3];tag=1234567890_[call_number]
  To: [$2]
  [last_Call-ID:]
  CSeq: 10 BYE
  Contact: sip:sipp;tgrp=1111@[local_ip]:[local_port]
  Max-Forwards: 70
  Subject: Performance Test
  Content-Length: 0

  ]]>
  </send>

  <recv response="200" crlf="true">
  </recv-->

  <recv request="BYE">
  </recv>

  <send crlf="true">
    <![CDATA[

      SIP/2.0 200 OK
      [last_From:]
      [last_To:]
      [last_Call-ID:]
      [last_CSeq:]
      [last_Via:]
      Contact: <sip:msml@[server_ip]:[local_port];transport=[transport]>
      Content-Length: 0

    ]]>
  </send>

  <!-- Keep the call open for a while in case the 200 is lost to be     -->
  <!-- able to retransmit it if we receive the BYE again.               -->
  <!-- pause milliseconds="4000"/-->
  <timewait milliseconds="4000"/>


  <!-- definition of the response time repartition table (unit is ms)   -->
  <ResponseTimeRepartition value="10, 20, 30, 40, 50, 100, 150, 200"/>

  <!-- definition of the call length repartition table (unit is ms)     -->
  <CallLengthRepartition value="10, 50, 100, 500, 1000, 5000, 10000"/>

</scenario>

[wdoekes]

Hi there. Thanks for the bug report.

I've tried to reproduce your issue, but I cannot, for a couple of reasons:

• I don't have your uac.xml, but I'll assume -sn uac works too
• you've supplied both -sn uas and -sf mrf.xml on the "uas" command line, I'll assume that the scenario pasted above is mrf.xml
• your "uas" listens on port 5010, while you connect to a different IP on port 5060; I have no insight in what that other machine does

However, I did run some valgrind tests in this branch: https://github.com/SIPp/sipp/tree/fix/valgrind
Perhaps you try that branch and run valgrind on your scenario: let it run until completion (you may need to add -m NUMBER to your sipp calls) and capture the output.

[gomting30]

Hi wdeokes
Thank you for your response. I'd like to emphasise that load test with ipv6 only did occur memory leak issue which means that test with ipv4 was OK.

Here is my answer for your failed reason.
•I don't have your uac.xml, but I'll assume -sn uac works too
-> I didn't post uac.xml here but actually had that scenario adapted by sipp and tested with it
-> Here is our sceanrio "uac.xml"

•you've supplied both -sn uas and -sf mrf.xml on the "uas" command line, I'll assume that the scenario pasted above is mrf.xml
-> Yes you are right. I deleted -sn uac in command line.

•your "uas" listens on port 5010, while you connect to a different IP on port 5060; I have no insight in what that other machine does
-> our sip flow is as the following
uac ipv6 ip -> B2BUA ipv6 ip:5060(udp port) -> uas ipv6 ip:5010(udp port)
-> But I executed load test without B2BUA (uac ipv6 ip -> uas ipv6 ip:5010) and we has the same result.

As your request, I will do run some valgrind tests on my scenrio and let you know the result soon.

[gomting30]

Running under Valgrind produced the following leak report. (10 calls were generated.)

==18556== Memcheck, a memory error detector
==18556== Copyright (C) 2002-2013, and GNU GPL'd, by Julian Seward et al.
==18556== Parent PID: 3314
==18556==
==18556== Syscall param socketcall.getsockname(namelen_in) points to uninitialised byte(s)
==18556== at 0x34F08E9827: getsockname (in /lib64/libc-2.12.so)
==18556== by 0x40F906: call::send_scene(int, int_, int_) (call.cpp:1162)
==18556== by 0x438A6A: pollset_process(int) (sipp.cpp:610)
==18556== Address 0xffefeda8c is on thread 1's stack
==18556==
==18556== Syscall param socketcall.getsockname(namelen_out) points to uninitialised byte(s)
==18556== at 0x34F08E9827: getsockname (in /lib64/libc-2.12.so)
==18556== by 0x40F906: call::send_scene(int, int_, int_) (call.cpp:1162)
==18556== by 0x40FC28: call::executeMessage(message_) (call.cpp:1419)
==18556== by 0x41127B: call::process_incoming(char_, sockaddr_storage_) (call.cpp:3340)
==18556== by 0x438A6A: pollset_process(int) (sipp.cpp:610)
==18556== by 0x4390FC: traffic_thread() (sipp.cpp:812)
==18556== by 0x43A8FE: main (sipp.cpp:2116)
==18556== Address 0xffefeda8c is on thread 1's stack
==18556== in frame #1, created by call::createSendingMessage(SendingMessage_, int, char_, int, int_) (
call.cpp:2038)
==18556==
==18556==
==18556== HEAP SUMMARY:
==18556== in use at exit: 112,045 bytes in 146 blocks
==18556== total heap usage: 1,625 allocs, 1,479 frees, 2,319,487 bytes allocated
==18556==
==18556== 460 bytes in 10 blocks are definitely lost in loss record 21 of 33
==18556== at 0x4A0720A: malloc (vg_replace_malloc.c:296)
==18556== by 0x40C0A9: call::createSendingMessage(SendingMessage_, int, char_, int, int_) (call.cpp:
2103)
==18556== by 0x40F906: call::send_scene(int, int_, int_) (call.cpp:1162)
==18556== by 0x40FC28: call::executeMessage(message_) (call.cpp:1419)
==18556== by 0x41127B: call::process_incoming(char_, sockaddr_storage_) (call.cpp:3340)
==18556== by 0x4263B5: process_message(sipp_socket_, char_, long, sockaddr_storage*) (socket.cpp:122
8)
==18556== by 0x438A6A: pollset_process(int) (sipp.cpp:610)
==18556== by 0x4390FC: traffic_thread() (sipp.cpp:812)
==18556== by 0x43A8FE: main (sipp.cpp:2116)
==18556==
==18556== LEAK SUMMARY:
==18556== definitely lost: 460 bytes in 10 blocks
==18556== indirectly lost: 0 bytes in 0 blocks
==18556== possibly lost: 0 bytes in 0 blocks
==18556== still reachable: 111,585 bytes in 136 blocks
==18556== suppressed: 0 bytes in 0 blocks
==18556== Reachable blocks (those to which a pointer was found) are not shown.
==18556== To see them, rerun with: --leak-check=full --show-leak-kinds=all
==18556==
==18556== For counts of detected and suppressed errors, rerun with: -v
==18556== Use --track-origins=yes to see where uninitialised values come from
==18556== ERROR SUMMARY: 21 errors from 3 contexts (suppressed: 4 from 4)

[gomting30]

This is memory leak point at sipp source code.
Refer to the following modified source code.

   if (server_sockaddr.ss_family == AF_INET6) {
            char * temp_dest;
            temp_dest = (char *) malloc(INET6_ADDRSTRLEN);
            memset(temp_dest,0,INET6_ADDRSTRLEN);
            inet_ntop(AF_INET6,
                      &((_RCAST(struct sockaddr_in6 *,&server_sockaddr))->sin6_addr),
                      temp_dest,
                      INET6_ADDRSTRLEN);
            dest += snprintf(dest, left, "%s",temp_dest);
        } else {
            dest += snprintf(dest, left, "%s",
                             inet_ntoa((_RCAST(struct sockaddr_in *,&server_sockaddr))->sin_addr));
        }

[vodik]

Looks like an easy enough fix, temp_dest is not being freed. Though the whole thing kinda looks over complicated. This could just be on getnameinfo call.

[vodik]

Thats annoyingly spammy. Sorry. @gomting30 does that do the trick?

[vodik]

@wdoekes Actually, this leak is visible with just the built-in uas/uac scenarios. Its just slow. I can verify I see memory usage going up in htop without this patch and it remaining stable with it. I need to poke at this some more, I'm not sure what I'm seeing.

[wdoekes]

Ah, it seems I already fixed that:
vodik@0026639
After that commit, the malloc is already gone.

We can still move to getnameinfo though.

[vodik]

Heh, nice. But I'm doubting this is where the leak is, at least not without some information about how heavy/long of a load test we're talking about. INET6_ADDRSTRLEN is 48 bytes, it would take 2.083×10^7 allocations, according to wolfram alpha, to reach 1G. If we allow an hour to leak 1G, we're talking ~5700 calls a second.

[gomting30]

@vodik yes we fixed the issue. there are no memory leak during load test.

[vodik]

@gomting30 awesome!

[wdoekes]

Very well, thanks for the feedback! Closing as "fixed in 0026639".