[SR-Users] kamailio very slow or stuck during period from time to time

Thibault Gueslin thibault.gueslin at gmail.com
Fri Nov 20 15:02:24 CET 2015


I am using a 4.3.3 version built myself from source.
(deb package were not released at that time)

I am expecting a few hundred connections.
(core.tcp_info or netstat )
Finally I have removed this line:
modparam("usrloc", "close_expired_tcp", 1)

It seems it was causing the memory leak.

I am still monitoring everything.


2015-11-20 14:07 GMT+01:00 Daniel-Constantin Mierla <miconda at gmail.com>:

> What is the exact version are you using (kamailio -v)?
>
> How many open connections do you expect to have at same time?
>
> Or get:
>
> kamcmd core.tcp_info
>
> Cheers,
> Daniel
>
>
> On 20/11/15 13:54, Thibault Gueslin wrote:
>
> It seems located in tcp connection:
>
> Nov 20 12:44:54 sip /usr/sbin/kamailio[30722]: NOTICE: qm_sums:
> summarizing all alloc'ed. fragments:
> Nov 20 12:44:54 sip /usr/sbin/kamailio[30722]: NOTICE: qm_sums:  count=
>   1 size=       800 bytes from <core>: cfg/cfg_struct.c:
> cfg_clone_global(626)
> Nov 20 12:44:54 sip /usr/sbin/kamailio[30722]: NOTICE: qm_sums:  count=
> 246 size=      9320 bytes from usrloc: urecord.c: new_urecord(65)
> Nov 20 12:44:54 sip /usr/sbin/kamailio[30722]: NOTICE: qm_sums:  count=
> 250 size=     58000 bytes from usrloc: ucontact.c: new_ucontact(98)
> Nov 20 12:44:54 sip /usr/sbin/kamailio[30722]: NOTICE: qm_sums:  count=
>  1279 size=     51288 bytes from usrloc: ../../ut.h: shm_str_dup(691)
> Nov 20 12:44:54 sip /usr/sbin/kamailio[30722]: NOTICE: qm_sums:  count=
>   8 size=      2048 bytes from tmx: tmx_pretran.c: tmx_check_pretran(271)
> Nov 20 12:44:54 sip /usr/sbin/kamailio[30722]: NOTICE: qm_sums:  count=
>   8 size=      1088 bytes from tmx: tmx_pretran.c: tmx_check_pretran(250)
> Nov 20 12:44:54 sip /usr/sbin/kamailio[30722]: NOTICE: qm_sums:  count=
> 246 size=     15856 bytes from usrloc: urecord.c: new_urecord(58)
> Nov 20 12:44:54 sip /usr/sbin/kamailio[30722]: NOTICE: qm_sums:  count=
>  2555 size=  43782480 bytes from <core>: tcp_main.c: tcpconn_new(957)
> Nov 20 12:44:54 sip /usr/sbin/kamailio[30722]: NOTICE: qm_sums:  count=
>   1 size=     12800 bytes from <core>: counters.c:
> counters_prefork_init(207)
> Nov 20 12:44:54 sip /usr/sbin/kamailio[30722]: NOTICE: qm_sums:  count=
>   1 size=      3840 bytes from sl: sl_stats.c: init_sl_stats_child(125)
> Nov 20 12:44:54 sip /usr/sbin/kamailio[30722]: NOTICE: qm_sums:  count=
>   1 size=       256 bytes from tmx: tmx_pretran.c:
> tmx_init_pretran_table(90)
> Nov 20 12:44:54 sip /usr/sbin/kamailio[30722]: NOTICE: qm_sums:  count=
>   1 size=      5120 bytes from tm: t_stats.c: init_tm_stats_child(60)
> Nov 20 12:44:54 sip /usr/sbin/kamailio[30722]: NOTICE: qm_sums:  count=
>   1 size=       960 bytes from kex: pkg_stats.c: pkg_proc_stats_init(79)
> Nov 20 12:44:54 sip /usr/sbin/kamailio[30722]: NOTICE: qm_sums:  count=
>   2 size=        64 bytes from <core>: cfg/cfg_struct.c: cfg_clone_str(130)
> Nov 20 12:44:54 sip /usr/sbin/kamailio[30722]: NOTICE: qm_sums:  count=
>   3 size=        64 bytes from usrloc: udomain.c: build_stat_name(51)
> Nov 20 12:44:54 sip /usr/sbin/kamailio[30722]: NOTICE: qm_sums:  count=
>   1 size=     40960 bytes from usrloc: udomain.c: new_udomain(93)
> Nov 20 12:44:54 sip /usr/sbin/kamailio[30722]: NOTICE: qm_sums:  count=
>   1 size=        48 bytes from usrloc: udomain.c: new_udomain(86)
> Nov 20 12:44:54 sip /usr/sbin/kamailio[30722]: NOTICE: qm_sums:  count=
>   1 size=        16 bytes from usrloc: dlist.c: new_dlist(556)
> Nov 20 12:44:54 sip /usr/sbin/kamailio[30722]: NOTICE: qm_sums:  count=
>   1 size=        32 bytes from usrloc: dlist.c: new_dlist(548)
> Nov 20 12:44:54 sip /usr/sbin/kamailio[30722]: NOTICE: qm_sums:  count=
>   1 size=         8 bytes from <core>: pt.c: init_pt(110)
> Nov 20 12:44:54 sip /usr/sbin/kamailio[30722]: NOTICE: qm_sums:  count=
>   1 size=         8 bytes from <core>: pt.c: init_pt(105)
> Nov 20 12:44:54 sip /usr/sbin/kamailio[30722]: NOTICE: qm_sums:  count=
>   1 size=      2800 bytes from <core>: pt.c: init_pt(104)
> Nov 20 12:44:54 sip /usr/sbin/kamailio[30722]: NOTICE: qm_sums:  count=
>   1 size=        24 bytes from app_lua: ../../lock_alloc.h:
> lock_set_alloc(70)
> Nov 20 12:44:54 sip /usr/sbin/kamailio[30722]: NOTICE: qm_sums:  count=
>   1 size=         8 bytes from app_lua: app_lua_api.c:
> lua_sr_alloc_script_ver(90)
> Nov 20 12:44:54 sip /usr/sbin/kamailio[30722]: NOTICE: qm_sums:  count=
>   1 size=        16 bytes from app_lua: app_lua_api.c:
> lua_sr_alloc_script_ver(83)
> Nov 20 12:44:54 sip /usr/sbin/kamailio[30722]: NOTICE: qm_sums:  count=
>   1 size=        72 bytes from <core>: timer.c: register_timer(1011)
> Nov 20 12:44:54 sip /usr/sbin/kamailio[30722]: NOTICE: qm_sums:  count=
>   1 size=     32768 bytes from htable: ht_api.c: ht_init_tables(336)
> Nov 20 12:44:54 sip /usr/sbin/kamailio[30722]: NOTICE: qm_sums:  count=
>   1 size=     65536 bytes from tsilo: ts_hash.c: init_ts_table(105)
> Nov 20 12:44:54 sip /usr/sbin/kamailio[30722]: NOTICE: qm_sums:  count=
>   1 size=      8208 bytes from tsilo: ../../lock_alloc.h: lock_set_alloc(70)
> Nov 20 12:44:54 sip /usr/sbin/kamailio[30722]: NOTICE: qm_sums:  count=
>   1 size=        32 bytes from tsilo: ts_hash.c: init_ts_table(75)
> Nov 20 12:44:54 sip /usr/sbin/kamailio[30722]: NOTICE: qm_sums:  count=
>   1 size=         8 bytes from cfgutils: cfgutils.c: mod_init(920)
> Nov 20 12:44:54 sip /usr/sbin/kamailio[30722]: NOTICE: qm_sums:  count=
>   1 size=         8 bytes from cfgutils: cfgutils.c: mod_init(914)
> Nov 20 12:44:54 sip /usr/sbin/kamailio[30722]: NOTICE: qm_sums:  count=
>   1 size=         8 bytes from cfgutils: cfgutils.c: mod_init(906)
> Nov 20 12:44:54 sip /usr/sbin/kamailio[30722]: NOTICE: qm_sums:  count=
>   1 size=        96 bytes from rtpproxy: rtpproxy.c: insert_rtpp_node(563)
> Nov 20 12:44:54 sip /usr/sbin/kamailio[30722]: NOTICE: qm_sums:  count=
>   1 size=        48 bytes from rtpproxy: rtpproxy.c: get_rtpp_set(535)
> Nov 20 12:44:54 sip /usr/sbin/kamailio[30722]: NOTICE: qm_sums:  count=
>   1 size=        16 bytes from rtpproxy: rtpproxy.c: mod_init(911)
> Nov 20 12:44:54 sip /usr/sbin/kamailio[30722]: NOTICE: qm_sums:  count=
>   1 size=         8 bytes from nathelper: nathelper.c: mod_init(662)
> Nov 20 12:44:54 sip /usr/sbin/kamailio[30722]: NOTICE: qm_sums:  count=
>   1 size=        40 bytes from tm: t_hooks.c: insert_tmcb(137)
> Nov 20 12:44:54 sip /usr/sbin/kamailio[30722]: NOTICE: qm_sums:  count=
>   1 size=        32 bytes from usrloc: ul_callback.c: register_ulcb(94)
> Nov 20 12:44:54 sip /usr/sbin/kamailio[30722]: NOTICE: qm_sums:  count=
>   1 size=        16 bytes from usrloc: ul_callback.c: init_ulcb_list(45)
> Nov 20 12:44:54 sip /usr/sbin/kamailio[30722]: NOTICE: qm_sums:  count=
>   1 size=      4112 bytes from usrloc: ../../lock_alloc.h:
> lock_set_alloc(70)
> Nov 20 12:44:54 sip /usr/sbin/kamailio[30722]: NOTICE: qm_sums:  count=
>   1 size=         8 bytes from sl: sl_funcs.c: sl_startup(83)
> Nov 20 12:44:54 sip /usr/sbin/kamailio[30722]: NOTICE: qm_sums:  count=
>   1 size=         8 bytes from sl: sl_stats.c: init_sl_stats(110)
> Nov 20 12:44:54 sip /usr/sbin/kamailio[30722]: NOTICE: qm_sums:  count=
>   1 size=        16 bytes from tm: t_hooks.c: init_tmcb_lists(74)
> Nov 20 12:44:54 sip /usr/sbin/kamailio[30722]: NOTICE: qm_sums:  count=
>   1 size=        16 bytes from tm: t_hooks.c: init_tmcb_lists(72)
> Nov 20 12:44:54 sip /usr/sbin/kamailio[30722]: NOTICE: qm_sums:  count=
>   1 size=   2097152 bytes from tm: h_table.c: init_hash_table(450)
> Nov 20 12:44:54 sip /usr/sbin/kamailio[30722]: NOTICE: qm_sums:  count=
>   2 size=        64 bytes from <core>: cfg/cfg_ctx.c: cfg_register_ctx(47)
> Nov 20 12:44:54 sip /usr/sbin/kamailio[30722]: NOTICE: qm_sums:  count=
>   1 size=      8192 bytes from <core>: tcp_main.c: init_tcp(4635)
> Nov 20 12:44:54 sip /usr/sbin/kamailio[30722]: NOTICE: qm_sums:  count=
>   1 size=     32768 bytes from <core>: tcp_main.c: init_tcp(4629)
> Nov 20 12:44:54 sip /usr/sbin/kamailio[30722]: NOTICE: qm_sums:  count=
>   1 size=         8 bytes from <core>: tcp_main.c: init_tcp(4621)
> Nov 20 12:44:54 sip /usr/sbin/kamailio[30722]: NOTICE: qm_sums:  count=
>   1 size=         8 bytes from <core>: tcp_main.c: init_tcp(4614)
> Nov 20 12:44:54 sip /usr/sbin/kamailio[30722]: NOTICE: qm_sums:  count=
>   1 size=         8 bytes from <core>: tcp_main.c: init_tcp(4607)
> Nov 20 12:44:54 sip /usr/sbin/kamailio[30722]: NOTICE: qm_sums:  count=
>   1 size=         8 bytes from <core>: tcp_main.c: init_tcp(4601)
> Nov 20 12:44:54 sip /usr/sbin/kamailio[30722]: NOTICE: qm_sums:  count=
>   1 size=         8 bytes from <core>: tcp_main.c: init_tcp(4589)
> Nov 20 12:44:54 sip /usr/sbin/kamailio[30722]: NOTICE: qm_sums:  count=
>   1 size=         8 bytes from <core>: usr_avp.c: init_avps(90)
> Nov 20 12:44:54 sip /usr/sbin/kamailio[30722]: NOTICE: qm_sums:  count=
>   1 size=         8 bytes from <core>: usr_avp.c: init_avps(89)
> Nov 20 12:44:54 sip /usr/sbin/kamailio[30722]: NOTICE: qm_sums:  count=
>   1 size=     16384 bytes from <core>: dst_blacklist.c:
> init_dst_blacklist(437)
> Nov 20 12:44:54 sip /usr/sbin/kamailio[30722]: NOTICE: qm_sums:  count=
>   1 size=         8 bytes from <core>: dst_blacklist.c:
> init_dst_blacklist(430)
> Nov 20 12:44:54 sip /usr/sbin/kamailio[30722]: NOTICE: qm_sums:  count=
>   2 size=        96 bytes from <core>: timer.c: timer_alloc(514)
> Nov 20 12:44:54 sip /usr/sbin/kamailio[30722]: NOTICE: qm_sums:  count=
>   1 size=         8 bytes from <core>: dns_cache.c: init_dns_cache(366)
> Nov 20 12:44:54 sip /usr/sbin/kamailio[30722]: NOTICE: qm_sums:  count=
>   1 size=     16384 bytes from <core>: dns_cache.c: init_dns_cache(358)
> Nov 20 12:44:54 sip /usr/sbin/kamailio[30722]: NOTICE: qm_sums:  count=
>   1 size=        16 bytes from <core>: dns_cache.c: init_dns_cache(351)
> Nov 20 12:44:54 sip /usr/sbin/kamailio[30722]: NOTICE: qm_sums:  count=
>   1 size=         8 bytes from <core>: dns_cache.c: init_dns_cache(345)
> Nov 20 12:44:54 sip /usr/sbin/kamailio[30722]: NOTICE: qm_sums:  count=
>   1 size=         8 bytes from <core>: timer.c: init_timer(283)
> Nov 20 12:44:54 sip /usr/sbin/kamailio[30722]: NOTICE: qm_sums:  count=
>   1 size=     16384 bytes from <core>: timer.c: init_timer(282)
> Nov 20 12:44:54 sip /usr/sbin/kamailio[30722]: NOTICE: qm_sums:  count=
>   1 size=         8 bytes from <core>: timer.c: init_timer(281)
> Nov 20 12:44:54 sip /usr/sbin/kamailio[30722]: NOTICE: qm_sums:  count=
>   1 size=         8 bytes from <core>: timer.c: init_timer(280)
> Nov 20 12:44:54 sip /usr/sbin/kamailio[30722]: NOTICE: qm_sums:  count=
>   1 size=         8 bytes from <core>: timer.c: init_timer(269)
> Nov 20 12:44:54 sip /usr/sbin/kamailio[30722]: NOTICE: qm_sums:  count=
>   1 size=         8 bytes from <core>: timer.c: init_timer(237)
> Nov 20 12:44:54 sip /usr/sbin/kamailio[30722]: NOTICE: qm_sums:  count=
>   1 size=    278544 bytes from <core>: timer.c: init_timer(220)
> Nov 20 12:44:54 sip /usr/sbin/kamailio[30722]: NOTICE: qm_sums:  count=
>   1 size=         8 bytes from <core>: timer.c: init_timer(219)
> Nov 20 12:44:54 sip /usr/sbin/kamailio[30722]: NOTICE: qm_sums:  count=
>   1 size=         8 bytes from <core>: timer.c: init_timer(206)
> Nov 20 12:44:54 sip /usr/sbin/kamailio[30722]: NOTICE: qm_sums:  count=
>   1 size=        64 bytes from <core>: cfg/cfg_struct.c:
> cfg_child_cb_new(830)
> Nov 20 12:44:54 sip /usr/sbin/kamailio[30722]: NOTICE: qm_sums:  count=
>   1 size=         8 bytes from <core>: cfg/cfg_struct.c: sr_cfg_init(361)
> Nov 20 12:44:54 sip /usr/sbin/kamailio[30722]: NOTICE: qm_sums:  count=
>   1 size=         8 bytes from <core>: cfg/cfg_struct.c: sr_cfg_init(354)
> Nov 20 12:44:54 sip /usr/sbin/kamailio[30722]: NOTICE: qm_sums:  count=
>   1 size=         8 bytes from <core>: cfg/cfg_struct.c: sr_cfg_init(347)
> Nov 20 12:44:54 sip /usr/sbin/kamailio[30722]: NOTICE: qm_sums:  count=
>   1 size=         8 bytes from <core>: cfg/cfg_struct.c: sr_cfg_init(335)
> Nov 20 12:44:54 sip /usr/sbin/kamailio[30722]: NOTICE: qm_sums:  count=
>   1 size=         8 bytes from <core>: cfg/cfg_struct.c: sr_cfg_init(323)
> Nov 20 12:44:54 sip /usr/sbin/kamailio[30722]: NOTICE: qm_sums:  count=
>   1 size=        72 bytes from mqueue: mqueue_api.c: mq_head_add(168)
> Nov 20 12:44:54 sip /usr/sbin/kamailio[30722]: NOTICE: qm_sums:  count=
>   1 size=        96 bytes from htable: ht_api.c: ht_add_table(275)
> Nov 20 12:44:54 sip /usr/sbin/kamailio[30722]: NOTICE: qm_sums:  count=
>   1 size=         8 bytes from <core>: mem/shm_mem.c:
> shm_mem_init_mallocs(179)
> Nov 20 12:44:54 sip /usr/sbin/kamailio[30722]: NOTICE: qm_sums:
> -----------------------------
>
>
> 2015-11-20 12:49 GMT+01:00 Daniel-Constantin Mierla < <miconda at gmail.com>
> miconda at gmail.com>:
>
>> If you get the shm used size increasing, run following commands:
>>
>> kamcmd cfg.set_now_int core memlog 1
>> kamcmd corex.shm_summary
>>
>> Do it after some time of running, when you see that the increase has
>> happened.
>>
>> Then take the logs from syslog related to shm summary and send them over
>> here.
>>
>> On the other hand, I saw recently some article about latency spikes for
>> tcp:
>>
>>   - https://http2.cloudflare.com/the-story-of-one-latency-spike/
>>
>> It is about http, but actually relates to tcp setting of os. Maybe you
>> can verify your values in OS.
>>
>> Cheers,
>> Daniel
>>
>>
>> On 20/11/15 12:40, Thibault Gueslin wrote:
>>
>> I am adding the info in a mqueue.
>> In a single rtimer, I am consuming the mqueue and calling a lua script.
>>
>> (I have followed the example of twitter).
>>
>> I have increase the number of tcp_children and I got issue for memory
>> allocation on allocations new tcp connection after a few hours.
>> Restart with SHMEM increased.
>> (but shame:used_size seems to increase)
>>
>> Regards
>>
>> 2015-11-19 11:55 GMT+01:00 Daniel-Constantin Mierla <miconda at gmail.com>:
>>
>>> Are you doing the http requests for all sip requests? How many rtimer
>>> processes do you have consuming from mqueue?
>>>
>>> What do you mean by "all tcp workers were busy"? They used lot of CPU?
>>>
>>> Cheers,
>>> Daniel
>>>
>>>
>>> On 19/11/15 01:30, Thibault Gueslin wrote:
>>>
>>> It seems to appear randomly.
>>>
>>> I don't have database access (default config without db)
>>> I have a mqueue with rtimer to do asynchronous http request.
>>>
>>> I have seen also sometimes that all tcp worker were busy even on a test
>>> server with 4 clients.
>>>
>>> Regards,
>>>
>>> Thibault
>>>
>>>
>>>
>>>
>>>
>>>
>>> Le 18 nov. 2015 à 13:28, Daniel-Constantin Mierla < <miconda at gmail.com>
>>> miconda at gmail.com> a écrit :
>>>
>>> Is it something repeating at constant interval of times, or are they
>>> random? Are you doing database queries in your config? Any of them via
>>> rtimer module?
>>>
>>> Cheers,
>>> Daniel
>>>
>>>
>>> On 18/11/15 12:00, Thibault Gueslin wrote:
>>>
>>> I am facing an issue with kamailio 4.3.3 that is very similar to
>>> http://lists.sip-router.org/pipermail/sr-users/2015-May/088195.html
>>>
>>> Had someone found the solution or faced similar issue ?
>>>
>>> Sometimes kamailio is receiving the message (check with wireshark, logs
>>> in tcp) but the message is not handled nor relayed.
>>> After a certain amount of time everything works fine.
>>>
>>> I will do what as has been advised : enabling pike & check with gdb when
>>> it appears.
>>>
>>> thibault
>>>
>>>
>>>
>>> _______________________________________________
>>> SIP Express Router (SER) and Kamailio (OpenSER) - sr-users mailing listsr-users at lists.sip-router.orghttp://lists.sip-router.org/cgi-bin/mailman/listinfo/sr-users
>>>
>>>
>>> --
>>> Daniel-Constantin Mierlahttp://twitter.com/#!/miconda - http://www.linkedin.com/in/miconda
>>> Book: SIP Routing With Kamailio - http://www.asipto.com
>>> Kamailio Advanced Training, Nov 30-Dec 2, Berlin - http://asipto.com/kat
>>>
>>>
>>> --
>>> Daniel-Constantin Mierlahttp://twitter.com/#!/miconda - http://www.linkedin.com/in/miconda
>>> Book: SIP Routing With Kamailio - http://www.asipto.com
>>> Kamailio Advanced Training, Nov 30-Dec 2, Berlin - http://asipto.com/kat
>>>
>>>
>>
>> --
>> Daniel-Constantin Mierlahttp://twitter.com/#!/miconda - http://www.linkedin.com/in/miconda
>> Book: SIP Routing With Kamailio - http://www.asipto.com
>> Kamailio Advanced Training, Nov 30-Dec 2, Berlin - http://asipto.com/kat
>>
>>
>
> --
> Daniel-Constantin Mierlahttp://twitter.com/#!/miconda - http://www.linkedin.com/in/miconda
> Book: SIP Routing With Kamailio - http://www.asipto.com
> Kamailio Advanced Training, Nov 30-Dec 2, Berlin - http://asipto.com/kat
>
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.sip-router.org/pipermail/sr-users/attachments/20151120/0d65f35a/attachment.html>


More information about the sr-users mailing list