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

Tue May 17 19:06:40 CEST 2016

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/imgs/opensips-solutions-logo.gif]<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><mailto:bogdan at opensips.org>
Enviado: terça-feira, 17 de maio de 2016 05:47
Para: Rodrigo Pimenta Carvalho; users at lists.opensips.org<mailto: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/imgs/opensips-solutions-logo.gif]<http://www.opensips-solutions.com/>

Home — OpenSIPS Solutions<http://www.opensips-solutions.com/>
www.opensips-solutions.com<http://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.

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><mailto: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/imgs/opensips-solutions-logo.gif]<http://www.opensips-solutions.com/>

Home — OpenSIPS Solutions<http://www.opensips-solutions.com/>
www.opensips-solutions.com<http://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<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/20160517/20c66b8e/attachment-0001.htm>