[OpenSIPS-Users] How to avoid many warnings about "handle_timer_job".

Tue May 17 18:03:23 CEST 2016

Hi Rodrigo,

I guess the root of your problem is this:
      ERROR: db_sqlite:db_sqlite_raw_query: query failed: database is 
locked.

If the DB query gets blocked on sqlite level, then the timer job will 
not terminate and the timer will complain on this -> you will get all 
the warnings from the timer:
WARNING:core:timer_ticker: timer task <ul-timer> already scheduled.......

Regards,

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

On 17.05.2016 14:57, Rodrigo Pimenta Carvalho wrote:
>
> Hi Bogdan-Andrei.
>
>
> For usrloc I had used the following configuration until 3 days ago, 
> and having the same problem:
>
>
> -----------------------------------------------------------------------------------------------------
>
> modparam("usrloc", "nat_bflag", "NAT")
> modparam("usrloc", "db_mode", 1)
> modparam("usrloc", "timer_interval",10)
> modparam("usrloc", "db_url",
>         "sqlite:///usr/local/opensips/db/sisc.sqlite") # CUSTOMIZE ME
> ------------------------------------------------------------------------------------------------------ 
>
>
>
> Since 3 days ago I started to use the following modified 
> configuration, and the problem disappeared:
>
>
> modparam("usrloc", "db_mode", 2)
> modparam("usrloc", "timer_interval",3)
>
> I'm still not sure that such modification in configuration is the 
> solution, because I still have to test several situations. Ex: using 
> TLS, TCP. Making calls (until now in my recent tests I didn't make 
> calls). Using a link to Internet (until know I'm using a LAN in my 
> recent tests). So, there are some scenarios that I still have to test 
> before confirming that I have gotten the solution. Until now I just 
> let 2 clients sending SIP REGISTER and nothing more.
>
> By the way, I'm using SQLite and I know that some times the log 
> presents the message:
>
> " ERROR: db_sqlite:db_sqlite_raw_query: query failed: database is locked."
>
> That is, sometimes a table can be locked, but it should be 
> responsibility of the DB_SQLite module to handle this condition, 
> shouldn't be?
> Do you think that SQLite can be causing such issue (delay in the 
> execution of the ul-timer)?
>
> Any hint will be very helpful!
>
> Thanks!
>
>
> RODRIGO PIMENTA CARVALHO
> Inatel Competence Center
> Software
> Ph: +55 35 3471 9200 RAMAL 979
>
>
> ------------------------------------------------------------------------
> *De:* Bogdan-Andrei Iancu <bogdan at opensips.org>
> *Enviado:* terça-feira, 17 de maio de 2016 05:47
> *Para:* Rodrigo Pimenta Carvalho; users at lists.opensips.org
> *Assunto:* Re: [OpenSIPS-Users] How to avoid many warnings about 
> "handle_timer_job".
> Hi Rodrigo,
>
> I'm back also. The logs indicate there is a serious delay in the 
> execution of the ul-timer (user location). According to your logs, it 
> is almost 15 minutes :O ..... What db_mode do you use in usrloc module ?
>
> Regards,
> Bogdan-Andrei Iancu
> OpenSIPS Founder and Developer
> http://www.opensips-solutions.com
> <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 11.05.2016 16:29, Rodrigo Pimenta Carvalho wrote:
>>
>> Hi. Just one more thing:
>>
>>
>> During my tests I have zero calls per second and zero parallel calls.
>>
>> I just let softphones sending SIP REGISTER messages, 1 at each minute.
>>
>> And I have just 4 softphones registering.
>>
>>
>> After all, we have changed the CPU clock, increasing it. For example:
>>
>>
>> we have used the command  "cpufreq-set -f 79200000" to change the 
>> clock to 792 MHz.
>>
>>
>> Before it, the clock used was less than 400 MHz.
>>
>>
>> Do you think it can really help us to avoid such warning in the log?
>>
>>
>> Best regards.
>>
>>
>>
>> Best regards.
>>
>>
>> RODRIGO PIMENTA CARVALHO
>> Inatel Competence Center
>> Software
>> Ph: +55 35 3471 9200 RAMAL 979
>>
>>
>> ------------------------------------------------------------------------
>> *De:* Rodrigo Pimenta Carvalho
>> *Enviado:* quarta-feira, 11 de maio de 2016 09:03
>> *Para:* Bogdan-Andrei Iancu
>> *Assunto:* Re: [OpenSIPS-Users] How to avoid many warnings about 
>> "handle_timer_job".
>>
>> Hi Bogdan-Andrei.
>>
>>
>> I'm back.
>>
>>
>> After coming back, I didn't see that log anymore.
>>
>>
>> However, another log appears every day:
>>
>>
>> "
>>
>> May 11 11:51:48 colibri-imx6-jfl opensips[2193]: May 11 11:51:48 
>> [2200] WARNING:core:timer_ticker: timer task <ul-timer> already 
>> schedualed for 940840 ms (now 20647710 ms)...y overlap..
>> "
>>
>>
>> When it starts to appear, I have to reset the OpenSIPS to avoid such 
>> messages.
>>
>>
>> My configurations :
>>
>> -------------------------------------------
>>
>> debug=3
>>
>> log_stderror=yes
>> log_facility=LOG_LOCAL1
>>
>> max_while_loops=200
>> sip_warning = 0
>> tcp_children=4
>>
>> fork=yes # para usar TLS deixe o fork = yes.
>> children=4
>> ----------------------------------------------------------
>>
>> Any suggestion?
>>
>>
>> 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, 4 de maio de 2016 05:38
>> *Para:* OpenSIPS users mailling list; Rodrigo Pimenta Carvalho
>> *Assunto:* Re: [OpenSIPS-Users] How to avoid many warnings about 
>> "handle_timer_job".
>> Hi Rodrigo,
>>
>> How many opensips process you have configured ?
>>
>> Do you have an estimation of the load on your opensips (in terms of 
>> calls per second and parallel calls) ?
>>
>> Best regards
>> Bogdan-Andrei Iancu
>> OpenSIPS Founder and Developer
>> http://www.opensips-solutions.com
>> <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 14.04.2016 15:06, Rodrigo Pimenta Carvalho wrote:
>>>
>>> Hi.
>>>
>>>
>>> Sometimes, the log of my OpenSIPS shows warnings like this:
>>>
>>>
>>>
>>> Apr 14 00:04:33 colibri-imx6 opensips[6909]: Apr 14 00:04:30 [6918] 
>>> WARNING:core:handle_timer_job: timer job <dlg-timer> has a 520000 us 
>>> delay in execution
>>> Apr 14 00:04:36 colibri-imx6 opensips[6909]: Apr 14 00:04:30 [6920] 
>>> WARNING:core:handle_timer_job: utimer job <tm-utimer> has a 520000 
>>> us delay in execution
>>> Apr 14 00:04:39 colibri-imx6 opensips[6909]: Apr 14 00:04:30 [6916] 
>>> WARNING:core:utimer_ticker: utimer task <tm-utimer> already 
>>> schedualed for 18348330 ms (now 18348960 ms), it may overlap..
>>> Apr 14 00:04:43 colibri-imx6 opensips[6909]: Apr 14 00:04:30 [6919] 
>>> WARNING:core:handle_timer_job: timer job <tm-timer> has a 520000 us 
>>> delay in execution
>>> Apr 14 00:04:53 colibri-imx6 opensips[6909]: Apr 14 00:04:31 [6919] 
>>> WARNING:core:handle_timer_job: timer job <blcore-expire> has a 
>>> 1070000 us delay in execution
>>> Apr 14 00:04:57 colibri-imx6 opensips[6909]: Apr 14 00:04:31 [6916] 
>>> WARNING:core:utimer_ticker: utimer task <tm-utimer> already 
>>> schedualed for 18349200 ms (now 18349400 ms), it may overlap..
>>> Apr 14 00:04:59 colibri-imx6 opensips[6909]: Apr 14 00:04:31 [6918] 
>>> WARNING:core:handle_timer_job: utimer job <tm-utimer> has a 200000 
>>> us delay in execution
>>> Apr 14 00:05:02 colibri-imx6 opensips[6909]: Apr 14 00:04:31 [6920] 
>>> WARNING:core:handle_timer_job: utimer job <tm-utimer> has a 200000 
>>> us delay in execution
>>> Apr 14 00:05:04 colibri-imx6 opensips[6909]: Apr 14 00:04:33 [6919] 
>>> WARNING:core:handle_timer_job: utimer job <tm-utimer> has a 400000 
>>> us delay in execution
>>> Apr 14 00:05:09 colibri-imx6 opensips[6909]: Apr 14 00:04:33 [6916] 
>>> WARNING:core:utimer_ticker: utimer task <tm-utimer> already 
>>> schedualed for 18350050 ms (now 18350450 ms), it may overlap..
>>> Apr 14 00:05:11 colibri-imx6 opensips[6909]: Apr 14 00:04:34 [6920] 
>>> WARNING:core:handle_timer_job: utimer job <tm-utimer> has a 680000 
>>> us delay in execution
>>> Apr 14 00:05:16 colibri-imx6 opensips[6909]: Apr 14 00:04:34 [6918] 
>>> WARNING:core:handle_timer_job: utimer job <tm-utimer> has a 680000 
>>> us delay in execution
>>> Apr 14 00:05:21 colibri-imx6 opensips[6909]: Apr 14 00:04:34 [6916] 
>>> WARNING:core:utimer_ticker: utimer task <tm-utimer> already 
>>> schedualed for 18350820 ms (now 18351500 ms), it may overlap..
>>> Apr 14 00:05:26 colibri-imx6 opensips[6909]: Apr 14 00:04:36 [6916] 
>>> WARNING:core:utimer_ticker: utimer task <tm-utimer> already 
>>> schedualed for 18352100 ms (now 18352300 ms), it may overlap..
>>> Apr 14 00:05:28 colibri-imx6 opensips[6909]: Apr 14 00:04:36 [6918] 
>>> WARNING:core:handle_timer_job: utimer job <tm-utimer> has a 200000 
>>> us delay in execution
>>> Apr 14 00:05:32 colibri-imx6 opensips[6909]: Apr 14 00:04:36 [6919] 
>>> WARNING:core:handle_timer_job: utimer job <tm-utimer> has a 200000 
>>> us delay in execution
>>> Apr 14 00:05:36 colibri-imx6 opensips[6909]: Apr 14 00:04:37 [6920] 
>>> WARNING:core:handle_timer_job: utimer job <tm-utimer> has a 
>>> 18352670000 us delay in execution
>>> Apr 14 00:05:38 colibri-imx6 opensips[6909]: Apr 14 00:04:38 [6918] 
>>> WARNING:core:handle_timer_job: utimer job <tm-utimer> has a 680000 
>>> us delay in execution
>>> Apr 14 00:05:41 colibri-imx6 opensips[6909]: Apr 14 00:04:38 [6919] 
>>> WARNING:core:handle_timer_job: timer job <tm-timer> has a 800000 us 
>>> delay in execution
>>> Apr 14 00:05:44 colibri-imx6 opensips[6909]: Apr 14 00:04:38 [6920] 
>>> WARNING:core:handle_timer_job: timer job <blcore-expire> has a 
>>> 800000 us delay in execution
>>>
>>>
>>>
>>> Any suggestion to avoid this or to use a specific configuration for 
>>> TM modules?
>>>
>>>
>>> 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
>>> http://lists.opensips.org/cgi-bin/mailman/listinfo/users
>>
>

-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.opensips.org/pipermail/users/attachments/20160517/232e60bf/attachment-0001.htm>