Memory Leak related to db_mysql/sip_trace

classic Classic list List threaded Threaded
8 messages Options
Reply | Threaded
Open this post in threaded view
|

Memory Leak related to db_mysql/sip_trace

Chevio
I have been doing some tests as I noticed that opensips is eating the system memory.

Test environment ubuntu 8.10, opensips 1.4.4 notls

Mysql.h

#define PROTOCOL_VERSION                10
#define MYSQL_SERVER_VERSION            "5.0.67"
#define MYSQL_BASE_VERSION              "mysqld-5.0"
#define MYSQL_SERVER_SUFFIX_DEF         "-0ubuntu6"


relevant modules for the test:

db_mysql
tncgw (custom module that uses db_mysql)
siptrace

started with 980Mb and ended with something around 140Mb Free after ~ 8000 incoming invites / 350 concurrent sessions. The memory was never released.

Then I decided to shutdown my custom module as it does intensive mysql usage, then repeat the above test with

db_mysql
siptrace

Started with 980Mb and ended with something around 480Mb Free, opensips did not release the memory after stopping the traffic, waiting 20 mins and then stopping it.

Then I decided to move the database to a different box thinking it could be Mysql Cache not releasing the cache memmory fast enough, but the results were the same as above.

Then I decided to shutdown completely db_mysql and siptrace and repeated the test. Opensips released almost all the memory after stopping it.

Ha any one had a similar problem ? What os version/ opesips version/mysql version is recommended that has been stress tested withoug memory leaks?.

Chevio


Reply | Threaded
Open this post in threaded view
|

Re: Memory Leak related to db_mysql/sip_trace

Vasil Kolev
В 23:02 -0700 на 15.03.2009 (нд), Chevio написа:
> I have been doing some tests as I noticed that opensips is eating the
> system
> memory.
>
...

This seems like a problem I've been discussing with Bogdan on irc - from
what I've seen in the DB layer code and the modules, if you fetch a
string from the database it's never freed - the memory is allocated in
the db_row functions, and db_free_row() is never called, except in error
conditions.

(There's also db_free_rows, which DOES NOT call db_free_row).

Chevio, which memory allocator are you using? I guess the system one,
judging by the fact that the memory manages to grow so much (the others
have a limited pool). Can you try enabling the memory allocator
debugger, running for a while with the mysql-intensive stuff and then
killing the process and seeing where do the allocations that were left
were done from?


--
Regards,
Vasil Kolev
Attractel NV
dCAP #1324, LPIC2


_______________________________________________
Devel mailing list
[hidden email]
http://lists.opensips.org/cgi-bin/mailman/listinfo/devel
Reply | Threaded
Open this post in threaded view
|

Re: Memory Leak related to db_mysql/sip_trace

Bogdan-Andrei Iancu
Hi guys,

Actually Vasil is right - during the latest changes in the DB API, by
mistake, the db rows were not freed anymore. But now it is fixed on SVN.

So, please update and test again.

Thanks and regards,
Bogdan

Vasil Kolev wrote:

> В 23:02 -0700 на 15.03.2009 (нд), Chevio написа:
>  
>> I have been doing some tests as I noticed that opensips is eating the
>> system
>> memory.
>>
>>    
> ...
>
> This seems like a problem I've been discussing with Bogdan on irc - from
> what I've seen in the DB layer code and the modules, if you fetch a
> string from the database it's never freed - the memory is allocated in
> the db_row functions, and db_free_row() is never called, except in error
> conditions.
>
> (There's also db_free_rows, which DOES NOT call db_free_row).
>
> Chevio, which memory allocator are you using? I guess the system one,
> judging by the fact that the memory manages to grow so much (the others
> have a limited pool). Can you try enabling the memory allocator
> debugger, running for a while with the mysql-intensive stuff and then
> killing the process and seeing where do the allocations that were left
> were done from?
>
>
>  


_______________________________________________
Devel mailing list
[hidden email]
http://lists.opensips.org/cgi-bin/mailman/listinfo/devel
Reply | Threaded
Open this post in threaded view
|

Re: Memory Leak related to db_mysql/sip_trace

Chevio
Thank you guys for looking into this problem. I was getting gray hairs already trying to find the memory leak on my custom module.

Vasil, I am using pkg_malloc, and pkg_free.

I changed the default memory per process to 4mb.

Bogdan, I Will get the fix from the SVN and compile it with it.

Chevio


Bogdan-Andrei Iancu wrote
Hi guys,

Actually Vasil is right - during the latest changes in the DB API, by
mistake, the db rows were not freed anymore. But now it is fixed on SVN.

So, please update and test again.

Thanks and regards,
Bogdan

Vasil Kolev wrote:
> В 23:02 -0700 на 15.03.2009 (нд), Chevio написа:
>  
>> I have been doing some tests as I noticed that opensips is eating the
>> system
>> memory.
>>
>>    
> ...
>
> This seems like a problem I've been discussing with Bogdan on irc - from
> what I've seen in the DB layer code and the modules, if you fetch a
> string from the database it's never freed - the memory is allocated in
> the db_row functions, and db_free_row() is never called, except in error
> conditions.
>
> (There's also db_free_rows, which DOES NOT call db_free_row).
>
> Chevio, which memory allocator are you using? I guess the system one,
> judging by the fact that the memory manages to grow so much (the others
> have a limited pool). Can you try enabling the memory allocator
> debugger, running for a while with the mysql-intensive stuff and then
> killing the process and seeing where do the allocations that were left
> were done from?
>
>
>  


_______________________________________________
Devel mailing list
Devel@lists.opensips.org
http://lists.opensips.org/cgi-bin/mailman/listinfo/devel
Reply | Threaded
Open this post in threaded view
|

Re: Memory Leak related to db_mysql/sip_trace

Chevio
In reply to this post by Vasil Kolev
After a lot of debugging and testing....

1. I bypassed the db and mysql modules, embedded mysql codde into my custom module and the behavior was the same.

2. I tested my mysql calls against valgrind and passed fine withoug memory leaks.

3.  I disabled all mysql related modules including my custom modules and did a simple test

setup a script that replies 484 to all invites. Sent 1000 invites.

Result..

the overall system memory goes down, the  memory per process grows up and is not released in a reasonable period of time (24h).

I tweaked the timers in tm module to see If it was just  keeping transactions memory too long but still see the same problem.

I have tested versions 1.4tls, notls, 1.5notls and the behavior is the same.

Just by starting and stoping opensips I end up with less free memory available.


I can't believe I am the only one having this problem. Has anyone noticed the same issue ?

I believe somewhere in the core the memory is not being released.

Please someone else test and confirm.

Chevio


Vasil Kolev wrote
В 23:02 -0700 на 15.03.2009 (нд), Chevio написа:
> I have been doing some tests as I noticed that opensips is eating the
> system
> memory.
>
...

This seems like a problem I've been discussing with Bogdan on irc - from
what I've seen in the DB layer code and the modules, if you fetch a
string from the database it's never freed - the memory is allocated in
the db_row functions, and db_free_row() is never called, except in error
conditions.

(There's also db_free_rows, which DOES NOT call db_free_row).

Chevio, which memory allocator are you using? I guess the system one,
judging by the fact that the memory manages to grow so much (the others
have a limited pool). Can you try enabling the memory allocator
debugger, running for a while with the mysql-intensive stuff and then
killing the process and seeing where do the allocations that were left
were done from?


--
Regards,
Vasil Kolev
Attractel NV
dCAP #1324, LPIC2


_______________________________________________
Devel mailing list
Devel@lists.opensips.org
http://lists.opensips.org/cgi-bin/mailman/listinfo/devel
Reply | Threaded
Open this post in threaded view
|

Re: Memory Leak related to db_mysql/sip_trace

Bogdan-Andrei Iancu
Hi Chevio,

Just to refresh me on this matter (and to make some light): it is about
the pkg memory or shm memory? which one is the was you suspect for the leak?

Have you tried to use the memory debugger and to monitor the used memory
values?

Regards,
Bogdan

Chevio wrote:

> After a lot of debugging and testing....
>
> 1. I bypassed the db and mysql modules, embedded mysql codde into my custom module and the behavior was the same.
>
> 2. I tested my mysql calls against valgrind and passed fine withoug memory leaks.
>
> 3.  I disabled all mysql related modules including my custom modules and did a simple test
>
> setup a script that replies 484 to all invites. Sent 1000 invites.
>
> Result..
>
> the overall system memory goes down, the  memory per process grows up and is not released in a reasonable period of time (24h).
>
> I tweaked the timers in tm module to see If it was just  keeping transactions memory too long but still see the same problem.
>
> I have tested versions 1.4tls, notls, 1.5notls and the behavior is the same.
>
> Just by starting and stoping opensips I end up with less free memory available.
>
>
> I can't believe I am the only one having this problem. Has anyone noticed the same issue ?
>
> I believe somewhere in the core the memory is not being released.
>
> Please someone else test and confirm.
>
> Chevio
>
>
>
> В 23:02 -0700 на 15.03.2009 (нд), Chevio написа:
>  
>> I have been doing some tests as I noticed that opensips is eating the
>> system
>> memory.
>>
>>    
> ...
>
> This seems like a problem I've been discussing with Bogdan on irc - from
> what I've seen in the DB layer code and the modules, if you fetch a
> string from the database it's never freed - the memory is allocated in
> the db_row functions, and db_free_row() is never called, except in error
> conditions.
>
> (There's also db_free_rows, which DOES NOT call db_free_row).
>
> Chevio, which memory allocator are you using? I guess the system one,
> judging by the fact that the memory manages to grow so much (the others
> have a limited pool). Can you try enabling the memory allocator
> debugger, running for a while with the mysql-intensive stuff and then
> killing the process and seeing where do the allocations that were left
> were done from?
>
>
>  


_______________________________________________
Devel mailing list
[hidden email]
http://lists.opensips.org/cgi-bin/mailman/listinfo/devel
Reply | Threaded
Open this post in threaded view
|

Re: Memory Leak related to db_mysql/sip_trace

Chevio
Hi Bogdan, thanks for the reply.

It looks like it is the SHM mem that has the problem. As I see the shared memory grow up and not released when I monitor opensips processes with top.

I compiled the code with the memory debugger but to be quite honest I coudn't make much sense of the dump at the end. I saw lists and lists of memory buckets allocated, freed, etc but I coudn't go beyond that.

This is what I see with top when I start opensips 1.5no tls:

Start:

top - 11:12:37 up 4 min,  1 user,  load average: 0.04, 0.22, 0.12
Tasks:  10 total,   0 running,  10 sleeping,   0 stopped,   0 zombie
Cpu(s):  0.0%us,  0.0%sy,  0.0%ni,100.0%id,  0.0%wa,  0.0%hi,  0.0%si,  0.0%st
Mem:   1033336k total,   131496k used,   901840k free,     6564k buffers
Swap:  1494004k total,        0k used,  1494004k free,    62452k cached

  PID USER      PR  NI  VIRT  RES  SHR S %CPU %MEM    TIME+  CODE DATA COMMAND
 5059 root      20   0  102m 1080  516 S    0  0.1   0:00.00 1028  32m opensips
 5058 root      20   0  102m  832  288 S    0  0.1   0:00.00 1028  32m opensips
 5057 root      20   0  102m  720  180 S    0  0.1   0:00.00 1028  32m opensips
 5056 root      20   0  102m 1964 1304 S    0  0.2   0:00.00 1028  32m opensips
 5055 root      20   0  102m 1980 1312 S    0  0.2   0:00.00 1028  32m opensips
 5054 root      20   0  102m 1200  636 S    0  0.1   0:00.00 1028  32m opensips
 5053 root      20   0  102m 1984 1312 S    0  0.2   0:00.00 1028  32m opensips
 5051 root      20   0  102m 3044 2504 S    0  0.3   0:00.00 1028  32m opensips
 4508 mysql     20   0  126m  21m 5568 S    0  2.2   0:00.56 6864 115m mysqld
 4466 root      20   0  1844  540  452 S    0  0.1   0:00.00   84  252 mysqld_safe


After some activity:

[cycle #: 516; if constant make sure server lives]
Server:: OpenSIPS (1.5.0-notls (i386/linux))
Now:: Tue Mar 31 11:34:38 2009
Up since:: Tue Mar 31 11:12:09 2009
Up time:: 1349 [sec]

Transaction Statistics:
tm:UAS_transactions = 31239
tm:UAC_transactions = 0
tm:inuse_transactions = 0

Stateless Server Statistics:
sl:sent_replies = 4911
sl:sent_err_replies = 58
sl:received_ACKs = 3576

UsrLoc Stats:
usrloc:registered_users = 2
usrloc:location-users = 2
usrloc:location-contacts = 2
usrloc:location-expires = 0

This is what I get from top:

top - 11:35:16 up 27 min,  2 users,  load average: 0.31, 0.74, 0.62
Tasks:  10 total,   0 running,  10 sleeping,   0 stopped,   0 zombie
Cpu(s):  0.3%us,  1.2%sy,  0.0%ni, 98.5%id,  0.0%wa,  0.0%hi,  0.0%si,  0.0%st
Mem:   1033336k total,   472296k used,   561040k free,    18268k buffers
Swap:  1494004k total,        0k used,  1494004k free,   355148k cached

  PID USER      PR  NI  VIRT  RES  SHR S %CPU %MEM    TIME+  CODE DATA COMMAND
 5059 root      20   0  102m 1084  520 S    0  0.1   0:00.50 1028  32m opensips
 5058 root      20   0  102m  10m 9696 S    0  1.0   0:00.70 1028  32m opensips
 5057 root      20   0  102m  720  180 S    0  0.1   0:00.14 1028  32m opensips
 5056 root      20   0  102m  13m 9.9m S    0  1.3   0:18.12 1028  32m opensips
 5055 root      20   0  102m  13m 9.9m S    0  1.3   0:18.20 1028  32m opensips
 5054 root      20   0  102m  13m 9.8m S    0  1.3   0:18.04 1028  32m opensips
 5053 root      20   0  102m  13m 9.8m S    0  1.3   0:18.00 1028  32m opensips
 5051 root      20   0  102m 3044 2504 S    0  0.3   0:00.00 1028  32m opensips
 4508 mysql     20   0  131m  39m 5948 S    0  3.9   5:36.60 6864 121m mysqld
 4466 root      20   0  1844  540  452 S    0  0.1   0:00.00   84  252 mysqld_safe


Those 9.8m in SHR memory are not released.


Chevio

Bogdan-Andrei Iancu wrote
Hi Chevio,

Just to refresh me on this matter (and to make some light): it is about
the pkg memory or shm memory? which one is the was you suspect for the leak?

Have you tried to use the memory debugger and to monitor the used memory
values?

Regards,
Bogdan

Chevio wrote:
> After a lot of debugging and testing....
>
> 1. I bypassed the db and mysql modules, embedded mysql codde into my custom module and the behavior was the same.
>
> 2. I tested my mysql calls against valgrind and passed fine withoug memory leaks.
>
> 3.  I disabled all mysql related modules including my custom modules and did a simple test
>
> setup a script that replies 484 to all invites. Sent 1000 invites.
>
> Result..
>
> the overall system memory goes down, the  memory per process grows up and is not released in a reasonable period of time (24h).
>
> I tweaked the timers in tm module to see If it was just  keeping transactions memory too long but still see the same problem.
>
> I have tested versions 1.4tls, notls, 1.5notls and the behavior is the same.
>
> Just by starting and stoping opensips I end up with less free memory available.
>
>
> I can't believe I am the only one having this problem. Has anyone noticed the same issue ?
>
> I believe somewhere in the core the memory is not being released.
>
> Please someone else test and confirm.
>
> Chevio
>
>
>
> В 23:02 -0700 на 15.03.2009 (нд), Chevio написа:
>  
>> I have been doing some tests as I noticed that opensips is eating the
>> system
>> memory.
>>
>>    
> ...
>
> This seems like a problem I've been discussing with Bogdan on irc - from
> what I've seen in the DB layer code and the modules, if you fetch a
> string from the database it's never freed - the memory is allocated in
> the db_row functions, and db_free_row() is never called, except in error
> conditions.
>
> (There's also db_free_rows, which DOES NOT call db_free_row).
>
> Chevio, which memory allocator are you using? I guess the system one,
> judging by the fact that the memory manages to grow so much (the others
> have a limited pool). Can you try enabling the memory allocator
> debugger, running for a while with the mysql-intensive stuff and then
> killing the process and seeing where do the allocations that were left
> were done from?
>
>
>  


_______________________________________________
Devel mailing list
Devel@lists.opensips.org
http://lists.opensips.org/cgi-bin/mailman/listinfo/devel
Reply | Threaded
Open this post in threaded view
|

Re: Memory Leak related to db_mysql/sip_trace

Bogdan-Andrei Iancu
Hi Chevio,

Just some insides of how shm memory works - opensips uses (from OS) a
fix amount of memory (it is what you configure via -m param at startup).
This amount of memory is reserved from OS at startup and it is not
changed anymore at runtime. So, whatever top shows is totally irrelevant
as there is no dynamic mem reservation at runtime.

So, the only relevant information about mem canbe fetched from OpenSIPS
(via MI - try "opensipsctl fifo get_statistics shmem:"

if you do not know how to interpret the final mem dump, pack the log and
email it to me - i will take a look to see if there are any signs of leak

Regards,
Bogdan

Chevio wrote:

> Hi Bogdan, thanks for the reply.
>
> It looks like it is the SHM mem that has the problem. As I see the shared memory grow up and not released when I monitor opensips processes with top.
>
> I compiled the code with the memory debugger but to be quite honest I coudn't make much sense of the dump at the end. I saw lists and lists of memory buckets allocated, freed, etc but I coudn't go beyond that.
>
> This is what I see with top when I start opensips 1.5no tls:
>
> Start:
>
> top - 11:12:37 up 4 min,  1 user,  load average: 0.04, 0.22, 0.12
> Tasks:  10 total,   0 running,  10 sleeping,   0 stopped,   0 zombie
> Cpu(s):  0.0%us,  0.0%sy,  0.0%ni,100.0%id,  0.0%wa,  0.0%hi,  0.0%si,  0.0%st
> Mem:   1033336k total,   131496k used,   901840k free,     6564k buffers
> Swap:  1494004k total,        0k used,  1494004k free,    62452k cached
>
>   PID USER      PR  NI  VIRT  RES  SHR S %CPU %MEM    TIME+  CODE DATA COMMAND
>  5059 root      20   0  102m 1080  516 S    0  0.1   0:00.00 1028  32m opensips
>  5058 root      20   0  102m  832  288 S    0  0.1   0:00.00 1028  32m opensips
>  5057 root      20   0  102m  720  180 S    0  0.1   0:00.00 1028  32m opensips
>  5056 root      20   0  102m 1964 1304 S    0  0.2   0:00.00 1028  32m opensips
>  5055 root      20   0  102m 1980 1312 S    0  0.2   0:00.00 1028  32m opensips
>  5054 root      20   0  102m 1200  636 S    0  0.1   0:00.00 1028  32m opensips
>  5053 root      20   0  102m 1984 1312 S    0  0.2   0:00.00 1028  32m opensips
>  5051 root      20   0  102m 3044 2504 S    0  0.3   0:00.00 1028  32m opensips
>  4508 mysql     20   0  126m  21m 5568 S    0  2.2   0:00.56 6864 115m mysqld
>  4466 root      20   0  1844  540  452 S    0  0.1   0:00.00   84  252 mysqld_safe
>
>
> After some activity:
>
> [cycle #: 516; if constant make sure server lives]
> Server:: OpenSIPS (1.5.0-notls (i386/linux))
> Now:: Tue Mar 31 11:34:38 2009
> Up since:: Tue Mar 31 11:12:09 2009
> Up time:: 1349 [sec]
>
> Transaction Statistics:
> tm:UAS_transactions = 31239
> tm:UAC_transactions = 0
> tm:inuse_transactions = 0
>
> Stateless Server Statistics:
> sl:sent_replies = 4911
> sl:sent_err_replies = 58
> sl:received_ACKs = 3576
>
> UsrLoc Stats:
> usrloc:registered_users = 2
> usrloc:location-users = 2
> usrloc:location-contacts = 2
> usrloc:location-expires = 0
>
> This is what I get from top:
>
> top - 11:35:16 up 27 min,  2 users,  load average: 0.31, 0.74, 0.62
> Tasks:  10 total,   0 running,  10 sleeping,   0 stopped,   0 zombie
> Cpu(s):  0.3%us,  1.2%sy,  0.0%ni, 98.5%id,  0.0%wa,  0.0%hi,  0.0%si,  0.0%st
> Mem:   1033336k total,   472296k used,   561040k free,    18268k buffers
> Swap:  1494004k total,        0k used,  1494004k free,   355148k cached
>
>   PID USER      PR  NI  VIRT  RES  SHR S %CPU %MEM    TIME+  CODE DATA COMMAND
>  5059 root      20   0  102m 1084  520 S    0  0.1   0:00.50 1028  32m opensips
>  5058 root      20   0  102m  10m 9696 S    0  1.0   0:00.70 1028  32m opensips
>  5057 root      20   0  102m  720  180 S    0  0.1   0:00.14 1028  32m opensips
>  5056 root      20   0  102m  13m 9.9m S    0  1.3   0:18.12 1028  32m opensips
>  5055 root      20   0  102m  13m 9.9m S    0  1.3   0:18.20 1028  32m opensips
>  5054 root      20   0  102m  13m 9.8m S    0  1.3   0:18.04 1028  32m opensips
>  5053 root      20   0  102m  13m 9.8m S    0  1.3   0:18.00 1028  32m opensips
>  5051 root      20   0  102m 3044 2504 S    0  0.3   0:00.00 1028  32m opensips
>  4508 mysql     20   0  131m  39m 5948 S    0  3.9   5:36.60 6864 121m mysqld
>  4466 root      20   0  1844  540  452 S    0  0.1   0:00.00   84  252 mysqld_safe
>
>
> Those 9.8m in SHR memory are not released.
>
>
> Chevio
>
>
> Hi Chevio,
>
> Just to refresh me on this matter (and to make some light): it is about
> the pkg memory or shm memory? which one is the was you suspect for the leak?
>
> Have you tried to use the memory debugger and to monitor the used memory
> values?
>
> Regards,
> Bogdan
>
> Chevio wrote:
>  
>> After a lot of debugging and testing....
>>
>> 1. I bypassed the db and mysql modules, embedded mysql codde into my custom module and the behavior was the same.
>>
>> 2. I tested my mysql calls against valgrind and passed fine withoug memory leaks.
>>
>> 3.  I disabled all mysql related modules including my custom modules and did a simple test
>>
>> setup a script that replies 484 to all invites. Sent 1000 invites.
>>
>> Result..
>>
>> the overall system memory goes down, the  memory per process grows up and is not released in a reasonable period of time (24h).
>>
>> I tweaked the timers in tm module to see If it was just  keeping transactions memory too long but still see the same problem.
>>
>> I have tested versions 1.4tls, notls, 1.5notls and the behavior is the same.
>>
>> Just by starting and stoping opensips I end up with less free memory available.
>>
>>
>> I can't believe I am the only one having this problem. Has anyone noticed the same issue ?
>>
>> I believe somewhere in the core the memory is not being released.
>>
>> Please someone else test and confirm.
>>
>> Chevio
>>
>>
>>
>> В 23:02 -0700 на 15.03.2009 (нд), Chevio написа:
>>  
>>    
>>> I have been doing some tests as I noticed that opensips is eating the
>>> system
>>> memory.
>>>
>>>    
>>>      
>> ...
>>
>> This seems like a problem I've been discussing with Bogdan on irc - from
>> what I've seen in the DB layer code and the modules, if you fetch a
>> string from the database it's never freed - the memory is allocated in
>> the db_row functions, and db_free_row() is never called, except in error
>> conditions.
>>
>> (There's also db_free_rows, which DOES NOT call db_free_row).
>>
>> Chevio, which memory allocator are you using? I guess the system one,
>> judging by the fact that the memory manages to grow so much (the others
>> have a limited pool). Can you try enabling the memory allocator
>> debugger, running for a while with the mysql-intensive stuff and then
>> killing the process and seeing where do the allocations that were left
>> were done from?
>>
>>
>>  
>>    
>
>
> _______________________________________________
> Devel mailing list
> [hidden email]
> http://lists.opensips.org/cgi-bin/mailman/listinfo/devel
>
>
>
>  


_______________________________________________
Devel mailing list
[hidden email]
http://lists.opensips.org/cgi-bin/mailman/listinfo/devel