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

Tue May 17 21:39:27 CEST 2016

Maybe John, the author of the sqlite driver in OpenSIPS has some 
information on this

Regards,

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

On 17.05.2016 20:06, Rodrigo Pimenta Carvalho wrote:
>
> Ok.
>
>
> I agree with you.
>
>
> But, do you have some comment on how to handle locked tables when I'm 
> using DB_SQLite module from OpenSIPS?
>
>
> I know that SQLite has a mechanism to handle this condition and I have 
> already used it in another project without OpenSIPs. But, as log as 
> the connection to SQLite is programmed in the OpenSIPS code, should I 
> do something more to deal with this kind of issue?
>
>
> Any hint will be very helpful!
>
>
> Regards.
>
>
> 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 13:03
> *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 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
> <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 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/0a16b6fd/attachment-0001.htm>