[OpenSIPS-Users] questions about WARNING:core:utimer_ticker

[Richard Revels]

Ah, Thank You.  Yes, I have come to the same conclusion that those messages
are after the problem rather than before.   I didn't take enough time to
really dig into the logs before send that message I reckon.


On Wed, Jun 25, 2025 at 1:20 PM Gregory Massel via Users <
users at lists.opensips.org> wrote:

> I get these on my most lightly loaded system, yet none at all on my most
> heavily loaded system...
>
> Although the error is generic enough that, on its own, it doesn't really
> help to determine what the problem is, on my system the tm-utimer messages
> are often accompanied by TLS errors such as:
>
> ERROR:tls_wolfssl:_wolfssl_tls_conn_shutdown: no ssl data
>
> ERROR:tm:msg_send: send() to x.x.x.x:5061 for proto tls/3 failed
>
> (Note: While I'm currently using WolfSSL, I previously used OpenSSL and
> experienced similar issues.)
> That's not to say that you're getting the error for the same reason as me;
> just to point out that there should be related errors before or after the
> tm-utimer warnings. It may be tricky to find them on a system with your
> sorts of volumes as, in my case, the TLS errors are typically just over 2
> minutes AFTER the tm-utimer warnings. On a busy system, a lot of unrelated
> log entries are likely to generate in between.
>
> The low-load system with these issue has outbound TLS. The high-load
> system without these issues does no outbound TLS; the only TLS it handles
> are inbound WSS connections.
>
> With regard to your question about threads, take a look at:
>
> https://www.opensips.org/Documentation/Script-CoreParameters-3-4#tcp_workers
>
> https://www.opensips.org/Documentation/Script-CoreParameters-3-4#udp_workers
>
> --Greg
>
> On 2025-06-24 18:52, Richard Revels via Users wrote:
>
> Greetings,
> I have started having issues with some proxies running opensips 3.2.19 and
> some others running 3.4.12
> With approximately 230 cps and 7300 dialogs the proxy starts emitting log
> messages like
>
> Jun 24 15:42:18 sip-proxy.local /usr/local/opensips/sbin/opensips[190328]:
> WARNING:core:utimer_ticker: utimer task <tm-utimer> already scheduled 150
> ms ago (now 3671145080 ms), delaying execution
> Jun 24 15:42:18 sip-proxy.local /usr/local/opensips/sbin/opensips[190328]:
> WARNING:core:utimer_ticker: utimer task <tm-utimer> already scheduled 200
> ms ago (now 3671145130 ms), delaying execution
> Jun 24 15:42:18 sip-proxy.local /usr/local/opensips/sbin/opensips[190328]:
> WARNING:core:utimer_ticker: utimer task <tm-utimer> already scheduled 300
> ms ago (now 3671145230 ms), delaying execution
> Jun 24 15:42:18 sip-proxy.local /usr/local/opensips/sbin/opensips[190328]:
> WARNING:core:utimer_ticker: utimer task <tm-utimer> already scheduled 400
> ms ago (now 3671145330 ms), delaying execution
> Jun 24 15:42:18 sip-proxy.local /usr/local/opensips/sbin/opensips[190328]:
> WARNING:core:utimer_ticker: utimer task <tm-utimer> already scheduled 500
> ms ago (now 3671145430 ms), delaying execution
> Jun 24 15:42:19 sip-proxy.local /usr/local/opensips/sbin/opensips[190328]:
> WARNING:core:utimer_ticker: utimer task <tm-utimer> already scheduled 600
> ms ago (now 3671145530 ms), delaying execution
> Jun 24 15:42:19 sip-proxy.local /usr/local/opensips/sbin/opensips[190328]:
> WARNING:core:utimer_ticker: utimer task <tm-utimer> already scheduled 700
> ms ago (now 3671145630 ms), delaying execution
> Jun 24 15:42:19 sip-proxy.local /usr/local/opensips/sbin/opensips[190328]:
> WARNING:core:utimer_ticker: utimer task <tm-utimer> already scheduled 800
> ms ago (now 3671145730 ms), delaying execution
> Jun 24 15:42:19 sip-proxy.local /usr/local/opensips/sbin/opensips[190328]:
> WARNING:core:utimer_ticker: utimer task <tm-utimer> already scheduled 900
> ms ago (now 3671145830 ms), delaying execution
> Jun 24 15:42:19 sip-proxy.local /usr/local/opensips/sbin/opensips[190328]:
> WARNING:core:timer_ticker: timer task <tm-timer> already scheduled 1000 ms
> ago (now 3671145830 ms), delaying execution
>
>
> The cpu usage on the threads goes from 3% - 11% depending on thread to 30%
> across the board.
>
> I have been running these versions of opensips for some time now (months
> for 3.4 and years for 3.2) and do see occasional latency in db or rest
> connection responses but only recently have started having this issue.
>
> So,
>
> How are SIP calls distributed across the processing threads?  I was
> thinking it would be round robin w/ attention given to busy or not.  but it
> seems like the lower pid threads do a lot more work on these proxies
>
> What are possible causes of the timers having trouble completing tasks?
> is it cpu use, waiting on some other task to finish, combination or more?
>
> Is there tuning that can be done to have more timer handling threads?  i
> tried this with modparam("tm", "timer_partitions") which seemed to make the
> problem worse
>
> Thank you in advance for any guidance you can give me on troubleshooting
> this issue.
> Richard Revels
>
>
>
> _______________________________________________
> Users mailing listUsers at lists.opensips.orghttp://lists.opensips.org/cgi-bin/mailman/listinfo/users
>
> _______________________________________________
> 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/20250625/8c5cfab6/attachment.html>