[Kamailio-Users] Understanding memory-leaks by inspecting PKG/SHM memory status at shutdown
Hi, according to the wiki page: http://www.kamailio.org/dokuwiki/doku.php/troubleshooting:memory
In order to detect a possible memory leak (in PGK or SHM) a good way is enabling memory debugging and shuting down the server, so:
"the memory manager will dump the memory status. Normally most of the memory is cleaned during shutdown. If there is memory leak, it should be visible as not-freed memory."
But I would like to know how exactly to detect if there is a memoty leak by inspecting the SHM/PKG status, something like this:
----------------------------------------------------------------------------------------------------------------------------- [32715]: Memory status (pkg): [32715]: fm_status (0x701a40): [32715]: heap size= 16777216 [32715]: used= 189696, used+overhead=247392, free=16529824 [32715]: max used (+overhead)= 247392 [32715]: dumping free list: [32715]: hash = 1 fragments no.: 1, unused: 0#012#011#011 bucket size: 8 - 8 (first 8) [32715]: hash = 2058 fragments no.: 1, unused: 0#012#011#011 bucket size: 8388608 - 16777216 (first 16530136) [32715]: TOTAL: 2 free fragments = 16530144 free bytes
[32678]: Memory status (shm): [32678]: fm_status (0x7fa57921c000): [32678]: heap size= 67108864 [32678]: used= 16, used+overhead=35872, free=67072992 [32678]: max used (+overhead)= 2821064 [32678]: dumping free list: [32678]: hash = 1 fragments no.: 45, unused: 0#012#011#011 bucket size: 8 - 8 (first 8) [32678]: hash = 2 fragments no.: 4, unused: 0#012#011#011 bucket size: 16 - 16 (first 16) [32678]: hash = 3 fragments no.: 16, unused: 0#012#011#011 bucket size: 24 - 24 (first 24) [32678]: hash = 4 fragments no.: 2, unused: 0#012#011#011 bucket size: 32 - 32 (first 32) [32678]: hash = 5 fragments no.: 1, unused: 0#012#011#011 bucket size: 40 - 40 (first 40) [32678]: hash = 6 fragments no.: 1, unused: 0#012#011#011 bucket size: 48 - 48 (first 48) [32678]: hash = 7 fragments no.: 39, unused: 0#012#011#011 bucket size: 56 - 56 (first 56) [32678]: hash = 8 fragments no.: 1, unused: 0#012#011#011 bucket size: 64 - 64 (first 64) [32678]: hash = 9 fragments no.: 1, unused: 0#012#011#011 bucket size: 72 - 72 (first 72) [32678]: hash = 10 fragments no.: 2, unused: 0#012#011#011 bucket size: 80 - 80 (first 80) [32678]: hash = 15 fragments no.: 1, unused: 0#012#011#011 bucket size: 120 - 120 (first 120) [32678]: hash = 25 fragments no.: 1, unused: 0#012#011#011 bucket size: 200 - 200 (first 200) [32678]: hash = 40 fragments no.: 5, unused: 0#012#011#011 bucket size: 320 - 320 (first 320) [32678]: hash = 112 fragments no.: 1, unused: 0#012#011#011 bucket size: 896 - 896 (first 896) [32678]: hash = 128 fragments no.: 4, unused: 0#012#011#011 bucket size: 1024 - 1024 (first 1024) [32678]: hash = 129 fragments no.: 2, unused: 0#012#011#011 bucket size: 1032 - 1032 (first 1032) [32678]: hash = 224 fragments no.: 1, unused: 0#012#011#011 bucket size: 1792 - 1792 (first 1792) [32678]: hash = 258 fragments no.: 3, unused: 0#012#011#011 bucket size: 2064 - 2064 (first 2064) [32678]: hash = 473 fragments no.: 1, unused: 0#012#011#011 bucket size: 3784 - 3784 (first 3784) [32678]: hash = 1026 fragments no.: 1, unused: 0#012#011#011 bucket size: 8208 - 8208 (first 8208) [32678]: hash = 2049 fragments no.: 2, unused: 0#012#011#011 bucket size: 16384 - 32768 (first 16512) [32678]: hash = 2051 fragments no.: 1, unused: 0#012#011#011 bucket size: 65536 - 131072 (first 98336) [32678]: hash = 2056 fragments no.: 1, unused: 0#012#011#011 bucket size: 2097152 - 4194304 (first 2621440) [32678]: hash = 2060 fragments no.: 1, unused: 0#012#011#011 bucket size: 33554432 - 67108864 (first 64287800) [32678]: TOTAL: 137 free fragments = 67072992 free bytes -----------------------------------------------------------------------------------------------------------------------------
This is, how should look this SHM/PKG status example (after shutdown) in case there is a memory leak? how to detect not-freed memory?
Thanks a lot.
Hello,
On 4/8/10 12:34 AM, Iñaki Baz Castillo wrote:
Hi, according to the wiki page: http://www.kamailio.org/dokuwiki/doku.php/troubleshooting:memory
In order to detect a possible memory leak (in PGK or SHM) a good way is enabling memory debugging and shuting down the server, so:
"the memory manager will dump the memory status. Normally most of the memory is cleaned during shutdown. If there is memory leak, it should be visible as not-freed memory."
But I would like to know how exactly to detect if there is a memoty leak by inspecting the SHM/PKG status, something like this:
[32715]: Memory status (pkg): [32715]: fm_status (0x701a40): [32715]: heap size= 16777216 [32715]: used= 189696, used+overhead=247392, free=16529824 [32715]: max used (+overhead)= 247392 [32715]: dumping free list: [32715]: hash = 1 fragments no.: 1, unused: 0#012#011#011 bucket size: 8 - 8 (first 8) [32715]: hash = 2058 fragments no.: 1, unused: 0#012#011#011 bucket size: 8388608 - 16777216 (first 16530136) [32715]: TOTAL: 2 free fragments = 16530144 free bytes
[32678]: Memory status (shm): [32678]: fm_status (0x7fa57921c000): [32678]: heap size= 67108864 [32678]: used= 16, used+overhead=35872, free=67072992 [32678]: max used (+overhead)= 2821064 [32678]: dumping free list: [32678]: hash = 1 fragments no.: 45, unused: 0#012#011#011 bucket size: 8 - 8 (first 8) [32678]: hash = 2 fragments no.: 4, unused: 0#012#011#011 bucket size: 16 - 16 (first 16) [32678]: hash = 3 fragments no.: 16, unused: 0#012#011#011 bucket size: 24 - 24 (first 24) [32678]: hash = 4 fragments no.: 2, unused: 0#012#011#011 bucket size: 32 - 32 (first 32) [32678]: hash = 5 fragments no.: 1, unused: 0#012#011#011 bucket size: 40 - 40 (first 40) [32678]: hash = 6 fragments no.: 1, unused: 0#012#011#011 bucket size: 48 - 48 (first 48) [32678]: hash = 7 fragments no.: 39, unused: 0#012#011#011 bucket size: 56 - 56 (first 56) [32678]: hash = 8 fragments no.: 1, unused: 0#012#011#011 bucket size: 64 - 64 (first 64) [32678]: hash = 9 fragments no.: 1, unused: 0#012#011#011 bucket size: 72 - 72 (first 72) [32678]: hash = 10 fragments no.: 2, unused: 0#012#011#011 bucket size: 80 - 80 (first 80) [32678]: hash = 15 fragments no.: 1, unused: 0#012#011#011 bucket size: 120 - 120 (first 120) [32678]: hash = 25 fragments no.: 1, unused: 0#012#011#011 bucket size: 200 - 200 (first 200) [32678]: hash = 40 fragments no.: 5, unused: 0#012#011#011 bucket size: 320 - 320 (first 320) [32678]: hash = 112 fragments no.: 1, unused: 0#012#011#011 bucket size: 896 - 896 (first 896) [32678]: hash = 128 fragments no.: 4, unused: 0#012#011#011 bucket size: 1024 - 1024 (first 1024) [32678]: hash = 129 fragments no.: 2, unused: 0#012#011#011 bucket size: 1032 - 1032 (first 1032) [32678]: hash = 224 fragments no.: 1, unused: 0#012#011#011 bucket size: 1792 - 1792 (first 1792) [32678]: hash = 258 fragments no.: 3, unused: 0#012#011#011 bucket size: 2064 - 2064 (first 2064) [32678]: hash = 473 fragments no.: 1, unused: 0#012#011#011 bucket size: 3784 - 3784 (first 3784) [32678]: hash = 1026 fragments no.: 1, unused: 0#012#011#011 bucket size: 8208 - 8208 (first 8208) [32678]: hash = 2049 fragments no.: 2, unused: 0#012#011#011 bucket size: 16384 - 32768 (first 16512) [32678]: hash = 2051 fragments no.: 1, unused: 0#012#011#011 bucket size: 65536 - 131072 (first 98336) [32678]: hash = 2056 fragments no.: 1, unused: 0#012#011#011 bucket size: 2097152 - 4194304 (first 2621440) [32678]: hash = 2060 fragments no.: 1, unused: 0#012#011#011 bucket size: 33554432 - 67108864 (first 64287800) [32678]: TOTAL: 137 free fragments = 67072992 free bytes
This is, how should look this SHM/PKG status example (after shutdown) in case there is a memory leak? how to detect not-freed memory?
it does not look as a dump with memory debugging on.
When memdbg is on, you should get something like:
0(17665) 1. N address=0xb5ab2440 frag=0xb5ab2428 size=4 used=1 0(17665) alloc'd from timer.c: init_timer(52)
Notice the "alloc'd ...' line which specifies the place where the memory was allocated.
A leak is signaled by many occurrences of allocation from same place (skipping the part of allocation done for config parsing and module initialization which happen only one, at startup).
Send kamailio -v to see if memory debugging is on.
Cheers, Daniel
2010/4/8 Daniel-Constantin Mierla miconda@gmail.com:
it does not look as a dump with memory debugging on.
SOrry, I just applied "MEMDBG=1" in one of the servers and got the output in the other.
When memdbg is on, you should get something like:
0(17665) 1. N address=0xb5ab2440 frag=0xb5ab2428 size=4 used=1 0(17665) alloc'd from timer.c: init_timer(52)
Notice the "alloc'd ...' line which specifies the place where the memory was allocated.
A leak is signaled by many occurrences of allocation from same place (skipping the part of allocation done for config parsing and module initialization which happen only one, at startup).
Thanks a lot, understood now. I will check it periodically.
2010/4/8 Iñaki Baz Castillo ibc@aliax.net:
2010/4/8 Daniel-Constantin Mierla miconda@gmail.com:
it does not look as a dump with memory debugging on.
SOrry, I just applied "MEMDBG=1" in one of the servers and got the output in the other.
When memdbg is on, you should get something like:
0(17665) 1. N address=0xb5ab2440 frag=0xb5ab2428 size=4 used=1 0(17665) alloc'd from timer.c: init_timer(52)
Notice the "alloc'd ...' line which specifies the place where the memory was allocated.
A leak is signaled by many occurrences of allocation from same place (skipping the part of allocation done for config parsing and module initialization which happen only one, at startup).
Hi again. I already have a kamailio 1.5.4 compiled with mem debugging (as "kamailio -V" shows DBG_QM_MALLOC flag).
In config file I have:
debug=3 memlog=3 # Same behaviour with 1 or 2 as it equal or less than 'debug'.
Unfortunatelly the ammount of logs it generates makes it unusable for production environment (~ 10 calls per second). Just restarting kamailio when memlog is enabled takes really long time (unfortuantelly I must restart it when adding new entries to 'address' table due to the issue when performing "fifo address_reload" which completely freezes kamailio sometimes).
Do I miss something? is it possible to log allocated and freeded memory without generating so many logs?
If not, I could use "memlog=1" without memory debugging compiled and I would check periodically the ammounf of PKG memory used. This is, I get this output:
kamailio[11770]: Memory status (pkg): kamailio[11770]: fm_status (0x701a40): kamailio[11770]: heap size= 16777216 kamailio[11770]: used= 190936, used+overhead=250696, free=16526520 kamailio[11770]: max used (+overhead)= 258464
I can check it periodically and inspect if the used memory is increasing. If so there must be a memleak. Am I right?
Thanks.
On 4/8/10 1:21 PM, Iñaki Baz Castillo wrote:
2010/4/8 Iñaki Baz Castilloibc@aliax.net:
2010/4/8 Daniel-Constantin Mierlamiconda@gmail.com:
it does not look as a dump with memory debugging on.
SOrry, I just applied "MEMDBG=1" in one of the servers and got the output in the other.
When memdbg is on, you should get something like:
0(17665) 1. N address=0xb5ab2440 frag=0xb5ab2428 size=4 used=1 0(17665) alloc'd from timer.c: init_timer(52)Notice the "alloc'd ...' line which specifies the place where the memory was allocated.
A leak is signaled by many occurrences of allocation from same place (skipping the part of allocation done for config parsing and module initialization which happen only one, at startup).
Hi again. I already have a kamailio 1.5.4 compiled with mem debugging (as "kamailio -V" shows DBG_QM_MALLOC flag).
In config file I have:
debug=3 memlog=3 # Same behaviour with 1 or 2 as it equal or less than 'debug'.
Unfortunatelly the ammount of logs it generates makes it unusable for production environment (~ 10 calls per second). Just restarting kamailio when memlog is enabled takes really long time (unfortuantelly I must restart it when adding new entries to 'address' table due to the issue when performing "fifo address_reload" which completely freezes kamailio sometimes).
Do I miss something? is it possible to log allocated and freeded memory without generating so many logs?
the goal is to see the places where the memory was allocated. That will give the proper hints about the leak.
What you can do is to print pkg status only when you send SIGUSR1 -- I attached a patch for that.
In this way, a restart does not print pkg and shm status, so it is fast. At runtime, when you send SIGUSR1 to a pid, the others can work just fine, so processing should not be affected that much. Use kamctl ps to spot the pid of an udp worker.
Cheers, Daniel
If not, I could use "memlog=1" without memory debugging compiled and I would check periodically the ammounf of PKG memory used. This is, I get this output:
kamailio[11770]: Memory status (pkg): kamailio[11770]: fm_status (0x701a40): kamailio[11770]: heap size= 16777216 kamailio[11770]: used= 190936, used+overhead=250696, free=16526520 kamailio[11770]: max used (+overhead)= 258464
I can check it periodically and inspect if the used memory is increasing. If so there must be a memleak. Am I right?
Thanks.
2010/4/8 Daniel-Constantin Mierla miconda@gmail.com:
Do I miss something? is it possible to log allocated and freeded memory without generating so many logs?
the goal is to see the places where the memory was allocated. That will give the proper hints about the leak.
What you can do is to print pkg status only when you send SIGUSR1 -- I attached a patch for that.
Great, I'll use it in the standby server and will test with SIPp in order to determine the possible memory leak.
In this way, a restart does not print pkg and shm status, so it is fast. At runtime, when you send SIGUSR1 to a pid, the others can work just fine, so processing should not be affected that much. Use kamctl ps to spot the pid of an udp worker.
For this purpose I've created a bash script which does the job for me :) I attach it.
In the production server (no mem debugging compiled) I've created a cron job which invokes the attached script every 5 minutes. Then with other scritp I filter the PKG status from kamailio log file (rsyslog logs it to a separate file) and get this output:
Apr 8 13:55:01 kamailio[11770]: used= 190936, used+overhead=250696, free=16526520 Apr 8 13:55:01 kamailio[11770]: max used (+overhead)= 258464 Apr 8 13:55:01 kamailio[11758]: used= 191176, used+overhead=250648, free=16526568 Apr 8 13:55:01 kamailio[11758]: max used (+overhead)= 257864 Apr 8 14:05:01 kamailio[11770]: used= 190936, used+overhead=250696, free=16526520 Apr 8 14:05:01 kamailio[11770]: max used (+overhead)= 258464 Apr 8 14:05:01 kamailio[11758]: used= 191176, used+overhead=250648, free=16526568 Apr 8 14:05:01 kamailio[11758]: max used (+overhead)= 257864
I cannot determine the memory leak cause with this, but I can determine that some memory exists if the 'used' value is increased, right?
Thanks a lot.
-
Daniel-Constantin Mierla -
Iñaki Baz Castillo