[OpenSIPS-Users] Is there new information about "WARNING ...tm-utimer...delay in execution" nowadays ?

Rodrigo Pimenta Carvalho pimenta at inatel.br
Wed Mar 22 17:29:56 EDT 2017 

Hi Bogdan.


Thank you for answering the questions.


In fact, today I moved my project to another hardware (2 CPUs and 516 MByte of RAM) and then I was able to see that OpenSIPS is working very well spending almost 0% of the CPUs. So there is no problem with the script opensips.cfg.


On the other hand, we have a sip client (softphone implemented by us) that even on this new environment it spends almost 100% of CPUs during calls. So, this softphone has a problem that was preventing the OpenSIPS to use the CPU in a normal way, as I suppose. In this case, I will focus my attention in such softphone for a while. Hopefully, by solving such issue, the entire system will run well even with 1 CPU and 256 MByte of RAM.


Best regards.


RODRIGO PIMENTA CARVALHO
Inatel Competence Center
Software
Ph: +55 35 3471 9200 RAMAL 979


________________________________
De: Bogdan-Andrei Iancu <bogdan at opensips.org>
Enviado: quarta-feira, 22 de março de 2017 17:38
Para: OpenSIPS users mailling list; Rodrigo Pimenta Carvalho
Assunto: Re: [OpenSIPS-Users] Is there new information about "WARNING ...tm-utimer...delay in execution" nowadays ?

Hi Rodrigo,

The issue you are reporting it is not the real problem, but a side effect of it. As you noticed, when opensips is under heavy load (CPU?), the internal timer system starts to generate warnings you see.

Now, the questions is: why is your opensips using 100% or why is it blocked (no processes available). Do you have any input on this ?

Regards,

Bogdan-Andrei Iancu
  OpenSIPS Founder and Developer
  http://www.opensips-solutions.com

OpenSIPS Summit May 2017 Amsterdam
  http://www.opensips.org/events/Summit-2017Amsterdam.html


[http://www.opensips.org/events/img/conference-image-2.jpg]<http://www.opensips.org/events/Summit-2017Amsterdam.html>

OpenSIPS Summit 2nd-5th May 2017, Amsterdam<http://www.opensips.org/events/Summit-2017Amsterdam.html>
www.opensips.org
OPENSIPS Summit 2017 "Great minds have purposes; others have wishes" Join us for three exciting days filled with VoIP and RTC presentations, workshops and design ...

[http://www.opensips-solutions.com/imgs/slideshow/slide1.jpg]<http://www.opensips-solutions.com/>

Home — OpenSIPS Solutions<http://www.opensips-solutions.com/>
www.opensips-solutions.com
OpenSIPS is a mature Open Source implementation of a SIP server. OpenSIPS is more than a SIP proxy/router as it includes application-level functionalities.

On 03/20/2017 09:10 PM, Rodrigo Pimenta Carvalho wrote:


Hi.


I have seen again that behavior from OpenSIPS that generates lots of warnings, like below:


Jan 01 06:19:08 colibri-imx6 opensips[1785]: Jan  1 06:19:08 [1792] WARNING:core:utimer_ticker: utimer task <tm-utimer> already scheduled for 21873780 ms (now 21873970 ms), it may overlap..
Jan 01 06:19:08 colibri-imx6 opensips[1785]: Jan  1 06:19:08 [1792] WARNING:core:utimer_ticker: utimer task <tm-utimer> already scheduled for 21873990 ms (now 21873990 ms), it may overlap..
Jan 01 06:19:08 colibri-imx6 opensips[1785]: Jan  1 06:19:08 [1793] WARNING:core:handle_timer_job: utimer job <tm-utimer> has a 190000 us delay in execution
Jan 01 06:19:26 colibri-imx6 opensips[1785]: Jan  1 06:19:26 [1792] WARNING:core:utimer_ticker: utimer task <tm-utimer> already scheduled for 0 ms (now 21891940 ms), it may overlap..
Jan 01 06:19:43 colibri-imx6 opensips[1785]: Jan  1 06:19:43 [1792] WARNING:core:utimer_ticker: utimer task <tm-utimer> already scheduled for 21908780 ms (now 21909000 ms), it may overlap..
Jan 01 06:19:43 colibri-imx6 opensips[1785]: Jan  1 06:19:43 [1792] WARNING:core:utimer_ticker: utimer task <tm-utimer> already scheduled for 21909010 ms (now 21909010 ms), it may overlap..
Jan 01 06:19:43 colibri-imx6 opensips[1785]: Jan  1 06:19:43 [1794] WARNING:core:handle_timer_job: utimer job <tm-utimer> has a 220000 us delay in execution
Jan 01 06:19:43 colibri-imx6 opensips[1785]: Jan  1 06:19:43 [1797] WARNING:core:handle_timer_job: timer job <tm-timer> has a 220000 us delay in execution
Jan 01 06:19:43 colibri-imx6 opensips[1785]: Jan  1 06:19:43 [1795] WARNING:core:handle_timer_job: timer job <dlg-timer> has a 220000 us delay in execution
Jan 01 06:19:43 colibri-imx6 opensips[1785]: Jan  1 06:19:43 [1793] WARNING:core:handle_timer_job: timer job <blcore-expire> has a 230000 us delay in execution
Jan 01 06:19:49 colibri-imx6 opensips[1785]: Jan  1 06:19:49 [1798] WARNING:core:handle_timer_job: utimer job <tm-utimer> has a 370000 us delay in execution
Jan 01 06:19:49 colibri-imx6 opensips[1785]: Jan  1 06:19:49 [1792] WARNING:core:utimer_ticker: utimer task <tm-utimer> already scheduled for 21914930 ms (now 21915300 ms), it may overlap..
Jan 01 06:19:49 colibri-imx6 opensips[1785]: Jan  1 06:19:49 [1792] WARNING:core:utimer_ticker: utimer task <tm-utimer> already scheduled for 21915320 ms (now 21915320 ms), it may overlap..
Jan 01 06:19:49 colibri-imx6 opensips[1785]: Jan  1 06:19:49 [1794] WARNING:core:handle_timer_job: utimer job <tm-utimer> has a 30000 us delay in execution
Jan 01 06:19:49 colibri-imx6 opensips[1785]: Jan  1 06:19:49 [1795] WARNING:core:handle_timer_job: utimer job <tm-utimer> has a 30000 us delay in execution

When it happens, I can see that OpenSIPS is using the CPU almost 100% of the time. And such behavior prevents others softwares in my system to work without problems. I see 6 process with 'OpenSIPS name and each one using 11% of CPU, for example. Now, the unique solution is to reboot the system.  Otherwise, the system remains instable and OpenSIPS continues using the CPU much more than usual.

Is there some new information about such issue that I should to know nowadays?
Is my hardware under minimals requirements to run OpenSIPS?
Is my script opensips.cfg wrong?

My system has the following characteristics:

    CPU clock = 996000
    CPU model name    = ARMv7 Processor rev 10 (v7l)
     Hardware    =  Freescale i.MX6 Quad/DualLite (Device Tree)

                           total       used          free     shared    buffers     cached
    Mem:        251140     157208      93932          0        196      26304



In my script opensips.cfg I have:
-----------------------------------------------
tcp_children=4
tcp_keepalive = 1
children=4
#fork=no
auto_aliases=no

#### Transaction Module
loadmodule "tm.so"
modparam("tm", "fr_timeout", 90)
modparam("tm", "fr_inv_timeout", 120)
modparam("tm", "T1_timer", 3000)
modparam("tm", "restart_fr_on_each_reply", 0)
modparam("tm", "onreply_avp_mode", 1)

Any hint will be very helpful!

Best regards.




RODRIGO PIMENTA CARVALHO
Inatel Competence Center
Software
Ph: +55 35 3471 9200 RAMAL 979



_______________________________________________
Users mailing list
Users at lists.opensips.org<mailto:Users at lists.opensips.org>
http://lists.opensips.org/cgi-bin/mailman/listinfo/users


-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.opensips.org/pipermail/users/attachments/20170322/91f7f239/attachment-0001.html>

More information about the Users mailing list