[SR-Users] kamailio very slow or stuck during period from time to time
Daniel-Constantin Mierla
miconda at gmail.com
Fri Nov 20 16:02:26 CET 2015
On 20/11/15 15:02, Thibault Gueslin wrote:
> I am using a 4.3.3 version built myself from source.
> (deb package were not released at that time)
kamailio -v shows the last git commit id when building from sources,
helping to identify exactly the snapshot of the source code that you built.
>
> 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.
Thanks for troubleshooting and pointing to this, I will investigate that
part of the code and see if I catch any reason for a leak there.
>
> I am still monitoring everything.
Let us know the results, would be good to nail it done properly.
Cheers,
Daniel
>
>
> 2015-11-20 14:07 GMT+01:00 Daniel-Constantin Mierla <miconda at gmail.com
> <mailto: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 <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://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/fdbf6966/attachment.html>
More information about the sr-users
mailing list