Hi,
I'm trying to debug a Kamailio which runs out of memory after a while. But following the hints at https://www.kamailio.org/wiki/tutorials/troubleshooting/memory doesn't help. I know it is the private memory that I'm missing. I already increased the pkg size to 16M, but somehow that seems to be not enough.
The Kamailio receives HEP messages, sends them to a lua script where it is processed. Overall there are not more than 10 custom private variables used.
In the log I'm seeing these messages:
Sep 19 17:04:42 salm /usr/sbin/kamailio[19134]: ERROR: app_lua [app_lua_api.c:726]: app_lua_run_ex(): error executing: handle_packet (err: 2) Sep 19 17:04:42 salm /usr/sbin/kamailio[19134]: ERROR: <script>: SCRIPT: failed to execute lua function! Sep 19 17:04:42 salm /usr/sbin/kamailio[19134]: ERROR: <core> [core/mem/q_malloc.c:292]: qm_find_free(): qm_find_free(0x7f9744eea010, 232); Free fragment not found! Sep 19 17:04:42 salm /usr/sbin/kamailio[19134]: ERROR: <core> [core/mem/q_malloc.c:425]: qm_malloc(): qm_malloc(0x7f9744eea010, 232) called from core: core/parser/msg_parser.c: get_ hdr_field(116), module: core; Free fragment not found! Sep 19 17:04:42 salm /usr/sbin/kamailio[19134]: ERROR: <core> [core/parser/msg_parser.c:118]: get_hdr_field(): out of memory Sep 19 17:04:42 salm /usr/sbin/kamailio[19134]: ERROR: <core> [core/parser/msg_parser.c:330]: parse_headers(): bad header field [Via: SIP/2.0/WSS o6m] Sep 19 17:04:42 salm /usr/sbin/kamailio[19134]: ERROR: pv [pv_core.c:647]: pv_get_callid(): cannot parse Call-Id header
kamcmd pkg.stats for this process gives me this output.
{ entry: 61 pid: 19134 rank: 61 used: 8748080 free: 4384 real_used: 16772832 total_size: 16777216 total_frags: 30 }
Now I tried to get a dump of what is in use, following the guidelines on the wiki page mentioned above, but without success.
I can easily start and stop the traffic coming in to Kamailio (by starting or stopping the captagent sending it there), but I can't get any output. Here's what I did:
captagent stop kamcmd cfg.set_now_int core memlog 1 kamcmd cfg.set_now_int core mem_dump_pkg 19134 captagent start ; sleep 1 ; captagent stop
(I started captagent so that the process actually had something to do because that's what the wiki page says it needs for printing memory information.)
During that second, there were quite a lot of packets running through this process, but I did not get a memory dump. A shm_summary dump however works as expected.
What am I missing? How do I get more information about what this process is using its memory for?
TIA Sebastian
Hello,
do you use kamailio.cfg variables in the lua script? If yes, can you show how you do it?
If you have troubles with pkg dump, it should be printed when you stop/restart. It would be good to do the pkg summary, it is easier to see the used chunks as a report. There are global parameters to configure it.
Cheers, Daniel
On 19.09.17 17:31, Sebastian Damm wrote:
Hi,
I'm trying to debug a Kamailio which runs out of memory after a while. But following the hints at https://www.kamailio.org/wiki/tutorials/troubleshooting/memory doesn't help. I know it is the private memory that I'm missing. I already increased the pkg size to 16M, but somehow that seems to be not enough.
The Kamailio receives HEP messages, sends them to a lua script where it is processed. Overall there are not more than 10 custom private variables used.
In the log I'm seeing these messages:
Sep 19 17:04:42 salm /usr/sbin/kamailio[19134]: ERROR: app_lua [app_lua_api.c:726]: app_lua_run_ex(): error executing: handle_packet (err: 2) Sep 19 17:04:42 salm /usr/sbin/kamailio[19134]: ERROR: <script>: SCRIPT: failed to execute lua function! Sep 19 17:04:42 salm /usr/sbin/kamailio[19134]: ERROR: <core> [core/mem/q_malloc.c:292]: qm_find_free(): qm_find_free(0x7f9744eea010, 232); Free fragment not found! Sep 19 17:04:42 salm /usr/sbin/kamailio[19134]: ERROR: <core> [core/mem/q_malloc.c:425]: qm_malloc(): qm_malloc(0x7f9744eea010, 232) called from core: core/parser/msg_parser.c: get_ hdr_field(116), module: core; Free fragment not found! Sep 19 17:04:42 salm /usr/sbin/kamailio[19134]: ERROR: <core> [core/parser/msg_parser.c:118]: get_hdr_field(): out of memory Sep 19 17:04:42 salm /usr/sbin/kamailio[19134]: ERROR: <core> [core/parser/msg_parser.c:330]: parse_headers(): bad header field [Via: SIP/2.0/WSS o6m] Sep 19 17:04:42 salm /usr/sbin/kamailio[19134]: ERROR: pv [pv_core.c:647]: pv_get_callid(): cannot parse Call-Id header
kamcmd pkg.stats for this process gives me this output.
{ entry: 61 pid: 19134 rank: 61 used: 8748080 free: 4384 real_used: 16772832 total_size: 16777216 total_frags: 30 }
Now I tried to get a dump of what is in use, following the guidelines on the wiki page mentioned above, but without success.
I can easily start and stop the traffic coming in to Kamailio (by starting or stopping the captagent sending it there), but I can't get any output. Here's what I did:
captagent stop kamcmd cfg.set_now_int core memlog 1 kamcmd cfg.set_now_int core mem_dump_pkg 19134 captagent start ; sleep 1 ; captagent stop
(I started captagent so that the process actually had something to do because that's what the wiki page says it needs for printing memory information.)
During that second, there were quite a lot of packets running through this process, but I did not get a memory dump. A shm_summary dump however works as expected.
What am I missing? How do I get more information about what this process is using its memory for?
TIA Sebastian
Kamailio (SER) - Users Mailing List sr-users@lists.kamailio.org https://lists.kamailio.org/cgi-bin/mailman/listinfo/sr-users
Hi Daniel,
thanks for the quick response. See my other mail with more details.
I don't use cfg variable from the lua script, I only access $shv(...) and $vn(...) or $var(...) and $sht(...) from it. And of course $tU, $hdr(...) and other builtin variables. Some of the variables I'm accessing might not be there always, though ($au for example).
Anything I can help with? I only need about half an hour to reproduce it.
Best Regards, Sebastian
On Tue, Sep 19, 2017 at 5:46 PM, Daniel-Constantin Mierla miconda@gmail.com wrote:
Hello,
do you use kamailio.cfg variables in the lua script? If yes, can you show how you do it?
If you have troubles with pkg dump, it should be printed when you stop/restart. It would be good to do the pkg summary, it is easier to see the used chunks as a report. There are global parameters to configure it.
Cheers, Daniel
Hello,
my guess is that you define many cfg variables from lua, which take from private memory (their definition).
So $sht(x=>abc) is defined when used first time and kept in memory. If you use also $sht(x=>efg), this is another defined variable.
This happens when you do KSR.pv.get("$sht(x=>abc)") or KSR.pv.get("$sht(x=>efg)")
To avoid defining a lot of variables, you can do:
KSR.pv.sets("$var(n)", "abc"); KSR.pv.get("$sht(x=>$var(n)"); KSR.pv.sets("$var(n)", "efg"); KSR.pv.get("$sht(x=>$var(n)");
The practically you define only one cfg variable, KSR.pv.get("$sht(x=>$var(n)")
The issue is known, there were other reporting it here on the mailing list. It's in my to-do before 5.1 to fix it in a way or another, by either setting a limit of defined variables and then throw error (easier), or track when a variable is used and start deleting the definition for older ones when the limit is exceeded.
Cheers, Daniel
On 19.09.17 17:56, Sebastian Damm wrote:
Hi Daniel,
thanks for the quick response. See my other mail with more details.
I don't use cfg variable from the lua script, I only access $shv(...) and $vn(...) or $var(...) and $sht(...) from it. And of course $tU, $hdr(...) and other builtin variables. Some of the variables I'm accessing might not be there always, though ($au for example).
Anything I can help with? I only need about half an hour to reproduce it.
Best Regards, Sebastian
On Tue, Sep 19, 2017 at 5:46 PM, Daniel-Constantin Mierla miconda@gmail.com wrote:
Hello,
do you use kamailio.cfg variables in the lua script? If yes, can you show how you do it?
If you have troubles with pkg dump, it should be printed when you stop/restart. It would be good to do the pkg summary, it is easier to see the used chunks as a report. There are global parameters to configure it.
Cheers, Daniel
Kamailio (SER) - Users Mailing List sr-users@lists.kamailio.org https://lists.kamailio.org/cgi-bin/mailman/listinfo/sr-users
Thanks Daniel,
looks like that is indeed the case. We the hash table key is the call-id, but we're not calling $sht(foo=>$ci) but instead passing in the call-id as a string.
Ich have now written a test script with those two functions:
function handle_packet_bad() callId = sr.pv.get("$ci") if sr.pv.get("$sht(interceptedSessions=>"..callId..")") ~= nil then sr.dbg("Lua found matching packet") end end
function handle_packet_good() callId = sr.pv.get("$ci") sr.pv.sets("$var(htableKey)", callId) if sr.pv.get("$sht(interceptedSessions=>$var(htableKey))") ~= nil then sr.dbg("Lua found matching packet") end end
Then in my Kamailio config, I call one or the other function depending on whether the PID is odd or even.
if ($pp & 1) { if(!lua_run("handle_packet_bad")) { xlog("L_ERR", "SCRIPT: failed to execute lua function!\n"); } } else { if(!lua_run("handle_packet_good")) { xlog("L_ERR", "SCRIPT: failed to execute lua function!\n"); } }
Now when I track the "real_mem" used by the UDP listeners, I see the difference. While the odd PIDs use more and more memory, the even ones stay about at the same level.
I wouldn't have found that by myself. Thanks again.
Best Regards, Sebastian
On Wed, Sep 20, 2017 at 10:56 AM, Daniel-Constantin Mierla miconda@gmail.com wrote:
Hello,
my guess is that you define many cfg variables from lua, which take from private memory (their definition).
So $sht(x=>abc) is defined when used first time and kept in memory. If you use also $sht(x=>efg), this is another defined variable.
This happens when you do KSR.pv.get("$sht(x=>abc)") or KSR.pv.get("$sht(x=>efg)")
To avoid defining a lot of variables, you can do:
KSR.pv.sets("$var(n)", "abc"); KSR.pv.get("$sht(x=>$var(n)"); KSR.pv.sets("$var(n)", "efg"); KSR.pv.get("$sht(x=>$var(n)");
The practically you define only one cfg variable, KSR.pv.get("$sht(x=>$var(n)")
The issue is known, there were other reporting it here on the mailing list. It's in my to-do before 5.1 to fix it in a way or another, by either setting a limit of defined variables and then throw error (easier), or track when a variable is used and start deleting the definition for older ones when the limit is exceeded.
Cheers, Daniel
On 19.09.17 17:56, Sebastian Damm wrote:
Hi Daniel,
thanks for the quick response. See my other mail with more details.
I don't use cfg variable from the lua script, I only access $shv(...) and $vn(...) or $var(...) and $sht(...) from it. And of course $tU, $hdr(...) and other builtin variables. Some of the variables I'm accessing might not be there always, though ($au for example).
Anything I can help with? I only need about half an hour to reproduce it.
Best Regards, Sebastian
On Tue, Sep 19, 2017 at 5:46 PM, Daniel-Constantin Mierla miconda@gmail.com wrote:
Hello,
do you use kamailio.cfg variables in the lua script? If yes, can you show how you do it?
If you have troubles with pkg dump, it should be printed when you stop/restart. It would be good to do the pkg summary, it is easier to see the used chunks as a report. There are global parameters to configure it.
Cheers, Daniel
Kamailio (SER) - Users Mailing List sr-users@lists.kamailio.org https://lists.kamailio.org/cgi-bin/mailman/listinfo/sr-users
-- Daniel-Constantin Mierla www.twitter.com/miconda -- www.linkedin.com/in/miconda Kamailio Advanced Training - www.asipto.com Kamailio World Conference - www.kamailioworld.com
The situation is like declaring:
int a; int b; ... int ...
in a C program -- it will run out of memory as well. As said, I plan to push a solution soon.
Cheers, Daniel
On 20.09.17 15:35, Sebastian Damm wrote:
Thanks Daniel,
looks like that is indeed the case. We the hash table key is the call-id, but we're not calling $sht(foo=>$ci) but instead passing in the call-id as a string.
Ich have now written a test script with those two functions:
function handle_packet_bad() callId = sr.pv.get("$ci") if sr.pv.get("$sht(interceptedSessions=>"..callId..")") ~= nil then sr.dbg("Lua found matching packet") end end
function handle_packet_good() callId = sr.pv.get("$ci") sr.pv.sets("$var(htableKey)", callId) if sr.pv.get("$sht(interceptedSessions=>$var(htableKey))") ~= nil then sr.dbg("Lua found matching packet") end end
Then in my Kamailio config, I call one or the other function depending on whether the PID is odd or even.
if ($pp & 1) { if(!lua_run("handle_packet_bad")) { xlog("L_ERR", "SCRIPT: failed to execute luafunction!\n"); } } else { if(!lua_run("handle_packet_good")) { xlog("L_ERR", "SCRIPT: failed to execute lua function!\n"); } }
Now when I track the "real_mem" used by the UDP listeners, I see the difference. While the odd PIDs use more and more memory, the even ones stay about at the same level.
I wouldn't have found that by myself. Thanks again.
Best Regards, Sebastian
On Wed, Sep 20, 2017 at 10:56 AM, Daniel-Constantin Mierla miconda@gmail.com wrote:
Hello,
my guess is that you define many cfg variables from lua, which take from private memory (their definition).
So $sht(x=>abc) is defined when used first time and kept in memory. If you use also $sht(x=>efg), this is another defined variable.
This happens when you do KSR.pv.get("$sht(x=>abc)") or KSR.pv.get("$sht(x=>efg)")
To avoid defining a lot of variables, you can do:
KSR.pv.sets("$var(n)", "abc"); KSR.pv.get("$sht(x=>$var(n)"); KSR.pv.sets("$var(n)", "efg"); KSR.pv.get("$sht(x=>$var(n)");
The practically you define only one cfg variable, KSR.pv.get("$sht(x=>$var(n)")
The issue is known, there were other reporting it here on the mailing list. It's in my to-do before 5.1 to fix it in a way or another, by either setting a limit of defined variables and then throw error (easier), or track when a variable is used and start deleting the definition for older ones when the limit is exceeded.
Cheers, Daniel
On 19.09.17 17:56, Sebastian Damm wrote:
Hi Daniel,
thanks for the quick response. See my other mail with more details.
I don't use cfg variable from the lua script, I only access $shv(...) and $vn(...) or $var(...) and $sht(...) from it. And of course $tU, $hdr(...) and other builtin variables. Some of the variables I'm accessing might not be there always, though ($au for example).
Anything I can help with? I only need about half an hour to reproduce it.
Best Regards, Sebastian
On Tue, Sep 19, 2017 at 5:46 PM, Daniel-Constantin Mierla miconda@gmail.com wrote:
Hello,
do you use kamailio.cfg variables in the lua script? If yes, can you show how you do it?
If you have troubles with pkg dump, it should be printed when you stop/restart. It would be good to do the pkg summary, it is easier to see the used chunks as a report. There are global parameters to configure it.
Cheers, Daniel
Kamailio (SER) - Users Mailing List sr-users@lists.kamailio.org https://lists.kamailio.org/cgi-bin/mailman/listinfo/sr-users
-- Daniel-Constantin Mierla www.twitter.com/miconda -- www.linkedin.com/in/miconda Kamailio Advanced Training - www.asipto.com Kamailio World Conference - www.kamailioworld.com
Kamailio (SER) - Users Mailing List sr-users@lists.kamailio.org https://lists.kamailio.org/cgi-bin/mailman/listinfo/sr-users
Okay, when restarting one of those operations I did earlier obviously made Kamailio dump all its private memory information. So I grepped everything from PID 19134 and then let the awk line from the Wiki page run over it. Now I'm lost interpreting the results. The top usages were those:
108 salm /usr/sbin/kamailio[19134]: WARNING: qm_status: alloc'd from core: core/rpc_lookup.c: rpc_hash_add(100) 166 salm /usr/sbin/kamailio[19134]: WARNING: qm_status: alloc'd from core: core/pvapi.c: pv_table_add(234) 195 salm /usr/sbin/kamailio[19134]: WARNING: qm_status: alloc'd from core: core/cfg.lex: addstr(1382) 1844 salm /usr/sbin/kamailio[19134]: WARNING: qm_status: alloc'd from htable: ht_var.c: pv_parse_ht_name(141) 1862 salm /usr/sbin/kamailio[19134]: WARNING: qm_status: alloc'd from core: core/pvapi.c: pv_cache_add(272) 1887 salm /usr/sbin/kamailio[19134]: WARNING: qm_status: alloc'd from core: core/pvapi.c: pv_parse_format(1075)
Can anybody explain what that means? When are those memory parts allocated?
As I see, those operations seem to have something to do with htables, right now there are absolutely no write operations, but for each packet there's at least one read operation on a hash table to see whether something is set for this Call-ID. All htable handling is done from my lua script. And private pseudo variables are used pretty much read-only as well. They might get zeroed at start of processing of the message, but right now none of them are set again later.
Thanks in advance, Sebastian
-
Daniel-Constantin Mierla -
Sebastian Damm