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

Daniel-Constantin Mierla miconda at gmail.com
Fri Nov 20 14:07:05 CET 2015


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
> <mailto: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 <mailto: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 <mailto: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 list
>>>>>         sr-users at lists.sip-router.org
>>>>>         <mailto:sr-users at lists.sip-router.org>
>>>>>         http://lists.sip-router.org/cgi-bin/mailman/listinfo/sr-users
>>>>
>>>>         -- 
>>>>         Daniel-Constantin Mierla
>>>>         http://twitter.com/#!/miconda <http://twitter.com/#%21/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 Mierla
>>         http://twitter.com/#!/miconda <http://twitter.com/#%21/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 Mierla
>     http://twitter.com/#!/miconda <http://twitter.com/#%21/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 Mierla
http://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/e0f67731/attachment.html>


More information about the sr-users mailing list