[SR-Users] kamailio memory leak in private memory

David Escartín Almudévar descartin at bts.io
Wed Feb 22 09:21:37 CET 2017


hello Daniel

we applied the change you suggested and monitored for a day and seems
the free pkg memory is stable. 
by now we are going to leave it this way and if we have to handle with a
hash in lua we will do in that way with a $var for the index
thanks a lot 

best regards
david


El lun, 20-02-2017 a las 19:48 +0100, Daniel-Constantin Mierla escribió:

> Hello,
> 
> this doesn't sound like a leak, but more like the side effect of
> defining a lot of variables, which use pkg memory.
> 
> In order to speed up (but also avoid some situations the could end up
> in leaks when parsing the pv spec allocates memory), kamailio is
> caching the definitions of the variables used in the scripts
> (kamailio.cfg, but also the scripts for embedded interpreters).
> 
> So, if you use:
> 
> $var(x) = "abc";
> 
> $sht(t=>$var(x)) = 1;
> 
> $var(x) = "xyz";
> 
> $sht(t=>$var(x)) = 1;
> 
> there are two definitions, respectively for: $var(x) and
> $sht(t=>$var(x)).
> 
> On the other hand, if you use:
> 
> $var(x) = "abc";
> 
> $sht(t=>$var(x)) = 1;
> 
> $sht(t=>xyz) = 1;
> 
> there are three definitions, respectively for: $var(x),
> $sht(t=>$var(x)) and $sht(t=>xyz). As you use different values after
> "t=>...", there will be different definitions.
> 
> 
> To avoid defining a lot of variable specs, you can try to do:
> 
>    local bbbb = string.match(variable_a, "^%+?.-([%d|#]+)$") or
> "anonymous"
>    sr.pv.sets("$var(vname)", bbbb)
>    local aaaa = sr.pv.get("$sht(table=>$var(vname))")
>     if not aaaa then
>         return
>     end
>     sr.pv.sets("$avp(s:cccc)", aaaa)
> 
> 
> I will try to think of a solution to avoid defining unlimited pv
> specs, but for the moment this should be a solution.
> 
> Cheers,
> Daniel
> 
> On 20/02/2017 18:42, david wrote:
> 
> > 
> > hello Daniel
> > 
> > We have been trying to isolate the issue as much as possible.
> > At first we though that since the issue was affecting only some UDP
> > receivers, it could be related with some customers traffic profile,
> > but since the decreased seemed abnormally "constant", and wondering
> > it might be related to a recent change we did on the configuration,
> > i think we finally found something that could be the cause (¿?)
> > 
> > when we query a hash table from a lua file, seems somehow private
> > memory is involved and not properly released. 
> > We just loaded a kamailio config file doing only this thing on
> > request route
> > request_route {
> >     
> >         xlog("L_INFO","Call-ID $ci: doing lua\n");
> >         lua_run("table","$fU");
> >         xlog("L_INFO","Call-ID $ci: done lua\n");
> >         drop();
> > }
> > 
> > the remarked lua command:
> > function table(variable_a)
> >     local bbbb = string.match(variable_a, "^%+?.-([%d|#]+)$") or
> > "anonymous"
> >    local aaaa = sr.pv.get("$sht(table=>" .. bbbb .. ")")
> >     if not aaaa then
> >         return
> >     end
> >     sr.pv.sets("$avp(s:cccc)", aaaa)
> > end
> > 
> > 
> > and launched some sip request to exceute the function, and this
> > seems to be causing the issue and doing the free pkg mem to
> > decrease. see file attached
> > (variable_a is passed to lua function as parameter from an $avp kam
> > variable too in some other tests and the result is also the same).
> > 
> > this is the log in debug mode when we make only a query on the hash
> > to assign it to a lua variable
> > 
> > 1(12776) INFO: Test Call-ID 1-15610 at 1.1.1.1: doing lua
> > 1(12776) WARNING: <core> [mem/f_malloc.c:439]: fm_malloc():
> > fm_malloc(0x7f9b2be0a010, 472) called from core:
> > parser/parse_from.c: parse_from_header(63)
> > 1(12776) WARNING: <core> [mem/f_malloc.c:514]: fm_malloc():
> > fm_malloc(0x7f9b2be0a010, 472) returns address 0x7f9b2be61990
> > 1(12776) WARNING: <core> [mem/f_malloc.c:439]: fm_malloc():
> > fm_malloc(0x7f9b2be0a010, 48) called from core:
> > parser/parse_addr_spec.c: parse_to_param(281)
> > 1(12776) WARNING: <core> [mem/f_malloc.c:514]: fm_malloc():
> > fm_malloc(0x7f9b2be0a010, 48) returns address 0x7f9b2be5f0c8
> > 1(12776) DEBUG: <core> [parser/parse_addr_spec.c:172]:
> > parse_to_param(): DEBUG: add_param: tag=15610SIPpTag001
> > 1(12776) DEBUG: <core> [parser/parse_addr_spec.c:894]:
> > parse_addr_spec(): end of header reached, state=29
> > 1(12776) DEBUG: app_lua [app_lua_api.c:643]: app_lua_run(): reload
> > deactivated
> > 1(12776) DEBUG: app_lua [app_lua_api.c:644]: app_lua_run():
> > executing Lua function: [[table]]
> > 1(12776) DEBUG: app_lua [app_lua_api.c:645]: app_lua_run(): lua top
> > index is: 4
> > 1(12776) DEBUG: app_lua [app_lua_sr.c:892]: lua_sr_pv_get(): pv get:
> > $sht(table=>2424627806)
> > 1(12776) WARNING: <core> [mem/f_malloc.c:439]: fm_malloc():
> > fm_malloc(0x7f9b2be0a010, 166) called from core: pvapi.c:
> > pv_cache_add(272)
> > 1(12776) WARNING: <core> [mem/f_malloc.c:514]: fm_malloc():
> > fm_malloc(0x7f9b2be0a010, 168) returns address 0x7f9b2be4a878
> > 1(12776) WARNING: <core> [mem/f_malloc.c:439]: fm_malloc():
> > fm_malloc(0x7f9b2be0a010, 32) called from htable: ht_var.c:
> > pv_parse_ht_name(135)
> > 1(12776) WARNING: <core> [mem/f_malloc.c:514]: fm_malloc():
> > fm_malloc(0x7f9b2be0a010, 32) returns address 0x7f9b2be4a800
> > 1(12776) DEBUG: htable [ht_var.c:172]: pv_parse_ht_name(): htable
> > [table] - key [2424627806]
> > 1(12776) WARNING: <core> [mem/f_malloc.c:439]: fm_malloc():
> > fm_malloc(0x7f9b2be0a010, 32) called from core: pvapi.c:
> > pv_parse_format(1075)
> > 1(12776) WARNING: <core> [mem/f_malloc.c:514]: fm_malloc():
> > fm_malloc(0x7f9b2be0a010, 32) returns address 0x7f9b2be5efb8
> > 1(12776) DEBUG: htable [ht_api.c:246]: ht_get_table(): htable found
> > [table]
> > 1(12776) DEBUG: <core> [pvapi.c:293]: pv_cache_add(): pvar
> > [$sht(table=>2424627806)] added in cache
> > 1(12776) WARNING: <core> [mem/f_malloc.c:439]: fm_malloc():
> > fm_malloc(0x7f9b2be0a010, 95) called from htable: ht_api.c:
> > ht_cell_pkg_copy(825)
> > 1(12776) WARNING: <core> [mem/f_malloc.c:514]: fm_malloc():
> > fm_malloc(0x7f9b2be0a010, 96) returns address 0x7f9b2be5ef10
> > 1(12776) WARNING: <core> [mem/f_malloc.c:575]: fm_free():
> > fm_free(0x7f9b2be0a010, 0x7f9b2be4acf8), called from htable:
> > ht_api.c: ht_cell_pkg_free(222)
> > 1(12776) WARNING: <core> [mem/f_malloc.c:594]: fm_free(): fm_free:
> > freeing block alloc'ed from htable: ht_api.c: ht_cell_pkg_copy(825)
> > 1(12776) DEBUG: app_lua [app_lua_sr.c:1014]: lua_sr_pv_sets(): pv
> > set: $avp(s:cccc)
> > 1(12776) DEBUG: <core> [pvapi.c:321]: pv_cache_lookup(): pvar
> > [$avp(s:cccc)] found in cache
> > 1(12776) WARNING: <core> [mem/f_malloc.c:439]: fm_malloc():
> > fm_malloc(0x7f9b222a1000, 75) called from core: usr_avp.c:
> > create_avp(175)
> > 1(12776) WARNING: <core> [mem/f_malloc.c:514]: fm_malloc():
> > fm_malloc(0x7f9b222a1000, 80) returns address 0x7f9b22ae7f88
> > 1(12776) INFO: Test Call-ID 1-15610 at 1.1.1.1: done lua
> > 
> > In this case the query found an entry on the hash table, but we
> > could duplicate that the free pkg memory is used and not properly
> > freeded when the match is not done in the hash table key either.
> > we don't understand well why this happens, since seems we are using
> > shared memory variables all the time (except the internal lua
> > variables).
> > Besides, we do usually do many sr.pv.sets and sr.pv.get functions to
> > several $avp (shared) and $var (private), but we never found this
> > issue or at least was not realized. The only thing i think we didnt
> > do so much is to read hash tables from lua like in this case.
> > 
> > By doing the query on the kamailio conf script file
> > $avp(s:cccc) = $sht(table=>$variable);
> > seems we are not suffering this leak, or at least is much much more
> > slow
> > 
> > 
> > we have tested this with kamailio 4.4.1, 4.4.5 and 5.0.0-rc1
> > versions, and seems the same.
> > 
> > do you think this has any sense or could be explained?
> > 
> > 
> > thanks a lot and regards
> > david
> > 
> > 
> > 
> > El vie, 17-02-2017 a las 15:49 +0100, david escribió:
> > 
> > > hello Daniel
> > > 
> > > i forgot to specify that in the dump attached, the first lines are
> > > for the process UDP receiver carrying the traffic on an affected
> > > IP, yesterday during the test we started the kamailio only with 1
> > > children per IP, so all the messages would have been processed by
> > > that process
> > > 
> > > i see that all the information of allocated mem for the root
> > > process is the same in both moments after and before the traffic
> > > load, but in the PID affected we see more hashes used after the
> > > load, i dont know how to deal with that information, anything you
> > > need from us please let us know and we will pleased to provide if
> > > possible
> > > 
> > > best regards
> > > david
> > > 
> > > 
> > > 
> > > El vie, 17-02-2017 a las 14:17 +0100, david escribió:
> > > 
> > > > hello DAniel
> > > > 
> > > > we have 4.4.1 sorry
> > > > we are only handling SIP calls without REGISTER messages
> > > > 
> > > > best regards
> > > > david
> > > > 
> > > > El vie, 17-02-2017 a las 13:53 +0100, Daniel-Constantin Mierla
> > > > escribió:
> > > > 
> > > > > Hello,
> > > > > 
> > > > > what kamailio version?
> > > > > 
> > > > > Are registrations handled by kamailio, or is just used for
> > > > > calls?
> > > > > 
> > > > > Cheers,
> > > > > Daniel
> > > > > 
> > > > > 
> > > > > 
> > > > > On 17/02/2017 13:31, david wrote:
> > > > > 
> > > > > 
> > > > > > Hello all
> > > > > > 
> > > > > > We are observing an issue in one kamailio proxy we use.
> > > > > > The consecuence of an unknow cause is that the private
> > > > > > memory of some UDP receiver processes in where we listen
> > > > > > from a particular IP, seems to be draining along the time
> > > > > > while processing traffic. Quite "slowly" but maybe aroung
> > > > > > 200K in 3-4hours, depending on the moment of the day.
> > > > > > 
> > > > > > This is quite weird for us, because it seemed like it was
> > > > > > caused by some particular traffic profile, since we have
> > > > > > several IP listening (8 children each) and we only see the
> > > > > > issue in the UDP receiver processes of some of those IPs.
> > > > > > Besides we have moved the kamailio service listening on the
> > > > > > same IP to several different physical servers, and the
> > > > > > behaviour is the same.
> > > > > > We look at it ussing pkg.stats kamcmd command and for
> > > > > > instance if we track one of the process affected
> > > > > > pid: 23784
> > > > > > rank: 53
> > > > > > used: 2838616
> > > > > > free: 13005408
> > > > > > real_used: 3771808
> > > > > > 
> > > > > > pid: 23784
> > > > > > rank: 53
> > > > > > used: 2842584
> > > > > > free: 12999280
> > > > > > real_used: 3777936
> > > > > > 
> > > > > > This 2 outputs were taken with 10min diff between each
> > > > > > other.
> > > > > > 
> > > > > > But we dont know where or how to look at it.
> > > > > > We have been these last days trying to search for patterns
> > > > > > to allocate some particular traffic source causing something
> > > > > > weird, but no luck.
> > > > > > We have checked all the SIP INVITE messages looking for
> > > > > > anything weird at any field but no luck, besides we
> > > > > > sometimes see some bad headers with blank spaces in the uri
> > > > > > or thing like that but those cases we have an error and we
> > > > > > dont think it can cause a memory leak.
> > > > > > Shared memory seems to be stable.
> > > > > > 
> > > > > > We also have checked the config we are using and we have
> > > > > > been discarding possible issues since we dont think the $var
> > > > > > variables we are using could cause that issue (but you never
> > > > > > know....)
> > > > > > 
> > > > > > We tried to debug the kamailio on one affected IP compiling
> > > > > > it with DBG_SYS_MALLOC , and doing the dump of the pkg mem
> > > > > > status when the kamailio was restarted and no traffic was
> > > > > > processed, and also when it had traffic processed. in this
> > > > > > last case, we removed traffic, waited for 20min and made the
> > > > > > dump
> > > > > > 
> > > > > > i attach you both files, we have the debug logs, but they
> > > > > > are very big to be passed here, and we dont know what to
> > > > > > look for :)
> > > > > > 
> > > > > > could you please give us some guidance or clue to at least
> > > > > > start to searching for something that can cause this issue?
> > > > > > 
> > > > > > thanks  alot and regards
> > > > > > david 
> > > > > > 
> > > > > > 
> > > > > > _______________________________________________
> > > > > > SIP Express Router (SER) and Kamailio (OpenSER) - sr-users mailing list
> > > > > > sr-users at lists.sip-router.org
> > > > > > http://lists.sip-router.org/cgi-bin/mailman/listinfo/sr-users
> > > > > 
> > > > > 
> > > > > 
> > > > > _______________________________________________
> > > > > SIP Express Router (SER) and Kamailio (OpenSER) - sr-users mailing list
> > > > > sr-users at lists.sip-router.org
> > > > > http://lists.sip-router.org/cgi-bin/mailman/listinfo/sr-users
> > > > 
> > > > 
> > 
> > 
> 
> 
> 
> -- 
> Daniel-Constantin Mierla
> www.twitter.com/miconda -- www.linkedin.com/in/miconda
> Kamailio Advanced Training - Mar 6-8 (Europe) and Mar 20-22 (USA) - www.asipto.com
> Kamailio World Conference - May 8-10, 2017 - www.kamailioworld.com


-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.sip-router.org/pipermail/sr-users/attachments/20170222/c03bbedd/attachment.html>


More information about the sr-users mailing list