Thanks for your help Daniel.

After trying memory dumping with sercmd and killall, I ended up using pkg_sums() before and after every block of dynamic memory allocation. What I found out (and scared me) is that my module finishes with no leak according to the memory summary but, somehow, the memory consumption grows in, what appears to be, a linear basis. 

Below the outputs per stage after the entry point function is called:

Stage 1:
Sep 10 19:58:29 carlosrdcnx-laptop kamailio: NOTICE: qm_sums:  count=    10 size=       256 bytes from cnx3a: cnx3a_parser.c: parse_body(122)
Sep 10 19:58:29 carlosrdcnx-laptop kamailio: NOTICE: qm_sums:  count=     1 size=        40 bytes from cnx3a: cnx3a_parser.c: parse_header(170)
Sep 10 19:58:29 carlosrdcnx-laptop kamailio: NOTICE: qm_sums:  count=     1 size=        40 bytes from cnx3a: cnx3a_mod.c: cnx3a_invite(1032)
Sep 10 19:58:29 carlosrdcnx-laptop kamailio: NOTICE: qm_sums:  count=    10 size=        88 bytes from cnx3a: cnx3a_parser.c: parse_body(88)
Sep 10 19:58:29 carlosrdcnx-laptop kamailio: NOTICE: qm_sums:  count=     1 size=      5000 bytes from cnx3a: cnx3a_mod.c: cnx3a_invite(972)
Sep 10 19:58:29 carlosrdcnx-laptop kamailio: NOTICE: qm_sums:  count=     1 size=      5000 bytes from cnx3a: cnx3a_mod.c: cnx3a_invite(971)
Sep 10 19:58:29 carlosrdcnx-laptop kamailio: NOTICE: qm_sums:  count=    10 size=        92 bytes from cnx3a: cnx3a_parser.c: parse_header(182)

In the final stage, the module is supposed to store a SIPURI and return. That SIPURI will later be consulted by the script using a PV, reason why, stage 2 ends with 28 bytes of memory usage.

pkg_str_dup() is called.

Stage2:
Sep 10 19:58:29 carlosrdcnx-laptop kamailio: NOTICE: qm_sums:  count=     1 size=        28 bytes from cnx3a: /usr/include/kamailio/parser/../ut.h: pkg_str_dup(720)

Afterwards, the module returns with 1.

Later when the script tries to write to a PV, the function in charge is called and if the value is assigned (str.s != NULL) it frees the internal variable first and then does another pkg_str_dup().

1st assignment. Before trying to free: 
Sep 10 19:58:29 carlosrdcnx-laptop kamailio: NOTICE: qm_sums:  count=     1 size=        28 bytes from cnx3a: /usr/include/kamailio/parser/../ut.h: pkg_str_dup(720)

1st assignment. After trying to free:
Sep 10 19:58:29 carlosrdcnx-laptop kamailio: NOTICE: qm_sums:  count=     1 size=        28 bytes from cnx3a: /usr/include/kamailio/parser/../ut.h: pkg_str_dup(720)

Same output since the var is null

1st assignment. After pkg_str_dup():
Sep 10 19:58:29 carlosrdcnx-laptop kamailio: NOTICE: <core> [mem/q_malloc.c:369]: qm_malloc(0xb71fd008, 27) called from cnx3a: /usr/include/kamailio/parser/../ut.h: pkg_str_dup(720)
Sep 10 19:58:29 carlosrdcnx-laptop kamailio: NOTICE: qm_sums:  count=     2 size=        56 bytes from cnx3a: /usr/include/kamailio/parser/../ut.h: pkg_str_dup(720)

-------------------------------------------------------------

2nd assignment. Before trying to free:
Sep 10 19:58:33 carlosrdcnx-laptop kamailio: NOTICE: qm_sums:  count=     2 size=        56 bytes from cnx3a: /usr/include/kamailio/parser/../ut.h: pkg_str_dup(720)

2nd assignment. After trying to free: 
Sep 10 19:58:33 carlosrdcnx-laptop kamailio: NOTICE: <core> [mem/q_malloc.c:437]: qm_free(0xb71fd008, 0xb7275dec), called from cnx3a: cnx3a_mod.c: pv_set_routes(2041)

Sep 10 19:58:33 carlosrdcnx-laptop kamailio: NOTICE: <core> [mem/q_malloc.c:461]: qm_free: freeing frag. 0xb7275dd4 alloc'ed from cnx3a: /usr/include/kamailio/parser/../ut.h: pkg_str_dup(720)

Sep 10 19:58:33 carlosrdcnx-laptop kamailio: NOTICE: qm_sums:  count=     1 size=        28 bytes from cnx3a: /usr/include/kamailio/parser/../ut.h: pkg_str_dup(720)

free() worked since var != NULL. We ended up with 28 bytes, which is correct.

2nd assignment. After pkg_str_dup():

Sep 10 19:58:33 carlosrdcnx-laptop kamailio: NOTICE: <core> [mem/q_malloc.c:369]: qm_malloc(0xb71fd008, 27) called from cnx3a: /usr/include/kamailio/parser/../ut.h: pkg_str_dup(720)
Sep 10 19:58:33 carlosrdcnx-laptop kamailio: NOTICE: qm_sums:  count=     2 size=        56 bytes from cnx3a: /usr/include/kamailio/parser/../ut.h: pkg_str_dup(720)

56 is correct.

Now, when the whole circuit is repeated for the second time, in Stage2 happens the following:

Sep 10 19:58:39 carlosrdcnx-laptop kamailio: NOTICE: <core> [mem/q_malloc.c:369]: qm_malloc(0xb71fd008, 27) called from cnx3a: /usr/include/kamailio/parser/../ut.h: pkg_str_dup(720)

Sep 10 19:58:39 carlosrdcnx-laptop kamailio: NOTICE: qm_sums:  count=     1 size=        32 bytes from cnx3a: /usr/include/kamailio/parser/../ut.h: pkg_str_dup(720)

-------------------------------------------------------------

Why pkg_malloc always gives 28 bytes instead of the 27 requested? Why the returned size is equal to 32 instead of just 27 in the last example? Can this be a memory fragmentation problem?

This happened after a few calls. Can this be the cause for a crash after running 40k calls?

I'm using kamailio 3.2.3.

Regards and thanks in advance.

Carlos

On Mon, Sep 10, 2012 at 12:18 PM, Daniel-Constantin Mierla <miconda@gmail.com> wrote:
Hello,


On 9/10/12 2:33 PM, Carlos Ruiz Díaz wrote:
Hi Daniel,

no, it's just a plain make && make install. 

I spent a few hours on debugging and I figured out that it was an off by one error on a memcpy() on certain exceptional conditions. I fixed that but then I found a memory leak that's causing the crash after 40k calls but I'm having a hard time interpreting the dump provided after sending the SIGUSR1 to the process. if I'm not mistaken, there are two pkg_str_dup() leaks per call but I'm still searching where I'm missing the pkg_free(). 

Is there a way to know where in the code the pkg_str_dup was called?

I tried with valgrind too, but after the macro expansion of the memory management functions, is very hard to find where it was called.

here are some hints about troubleshooting memory:
http://www.asipto.com/pub/kamailio-devel-guide/#c04troubleshooting

if you set memdbg and memlog lower than debug global parameter, then you get all memory operations in the syslog (be sure you compile with MEMDBG=1). Also look at mem_summary:
http://www.kamailio.org/wiki/cookbooks/3.3.x/core#mem_summary

and cfgutils module readme for some functions that can be used in config to dump the memory usage.

Cheers,
Daniel




Regards.

Carlos.



On Mon, Sep 10, 2012 at 4:02 AM, Daniel-Constantin Mierla <miconda@gmail.com> wrote:
Hello,

yes, by default is with debug symbols on. Do you provide special flags or parameters to the make command?

Cheers,
Daniel


On 9/8/12 9:39 PM, Carlos Ruiz Díaz wrote:
Hello list,

I'm trying to debug my module after it crashed by SIGSEGV, but the problem is that I'm unable to see the relevant data in the core file that's being dumped after the crash.

For example, if I do bt full, I get:

0  0x0ef0f494 in append_string () from /opt/install/kamailio-3.2.3/lib/kamailio/modules_k/cnx3a.so
No symbol table info available.
#1  0x0eef9658 in build_message () from /opt/install/kamailio-3.2.3/lib/kamailio/modules_k/cnx3a.so
No symbol table info available.
Backtrace stopped: frame did not save the PC

Only the functions that were called but no parameter values. 

AFAIK, if I compile kamailio from sources, it is by default compiled with the -g option, so, it looks like that I'm missing something else.

Regards.

Carlos.


_______________________________________________
sr-dev mailing list
sr-dev@lists.sip-router.org
http://lists.sip-router.org/cgi-bin/mailman/listinfo/sr-dev


-- 
Daniel-Constantin Mierla - http://www.asipto.com
http://twitter.com/#!/miconda - http://www.linkedin.com/in/miconda
Kamailio Advanced Training, Berlin, Nov 5-8, 2012 - http://asipto.com/u/kat
Kamailio Advanced Training, Miami, USA, Nov 12-14, 2012 - http://asipto.com/u/katu


-- 
Daniel-Constantin Mierla - http://www.asipto.com
http://twitter.com/#!/miconda - http://www.linkedin.com/in/miconda
Kamailio Advanced Training, Berlin, Nov 5-8, 2012 - http://asipto.com/u/kat
Kamailio Advanced Training, Miami, USA, Nov 12-14, 2012 - http://asipto.com/u/katu