Hi Dan,
I'm experiencing same on 2.3.5 as per my initial email. still couldn't find out
the exact reason. btw are you using a virtualise environment ?
On Thursday, 20 September 2018, 7:35:28 PM GMT+5:30, Dan Pascu
<[email protected]> wrote:
Here is a follow up on this problem. I started to use the system to do some
testing. I only have 1 device registered that makes some calls. I started to
notice similar type of messages, but with a slightly different pattern while
testing it. They seem to happen more often when I end the call, but I cannot
unequivocally tie the behavior to that because it doesn't happen always when I
end a call, it just seems to be triggered more often during that time.
I see a string of warnings about timers that continue for about 30 seconds
after which they stop, like below (I trimmed the output because it's just
repeating every 90-100ms and the log would be too long, so I only pasted the
start and the end of it):
Sep 20 10:28:34 node03 /usr/sbin/opensips[30302]: WARNING:core:utimer_ticker:
utimer task <tm-utimer> already scheduled 100 ms ago (now 1208830 ms), delaying
execution
Sep 20 10:28:34 node03 /usr/sbin/opensips[30302]: WARNING:core:utimer_ticker:
utimer task <tm-utimer> already scheduled 200 ms ago (now 1208930 ms), delaying
execution
Sep 20 10:28:34 node03 /usr/sbin/opensips[30302]: WARNING:core:utimer_ticker:
utimer task <tm-utimer> already scheduled 300 ms ago (now 1209030 ms), delaying
execution
Sep 20 10:28:34 node03 /usr/sbin/opensips[30302]: WARNING:core:utimer_ticker:
utimer task <tm-utimer> already scheduled 400 ms ago (now 1209130 ms), delaying
execution
Sep 20 10:28:34 node03 /usr/sbin/opensips[30302]: WARNING:core:utimer_ticker:
utimer task <tm-utimer> already scheduled 500 ms ago (now 1209230 ms), delaying
execution
Sep 20 10:28:34 node03 /usr/sbin/opensips[30302]: WARNING:core:utimer_ticker:
utimer task <tm-utimer> already scheduled 600 ms ago (now 1209330 ms), delaying
execution
Sep 20 10:28:34 node03 /usr/sbin/opensips[30302]: WARNING:core:utimer_ticker:
utimer task <tm-utimer> already scheduled 700 ms ago (now 1209430 ms), delaying
execution
Sep 20 10:28:34 node03 /usr/sbin/opensips[30302]: WARNING:core:utimer_ticker:
utimer task <tm-utimer> already scheduled 800 ms ago (now 1209530 ms), delaying
execution
Sep 20 10:28:34 node03 /usr/sbin/opensips[30302]: WARNING:core:utimer_ticker:
utimer task <tm-utimer> already scheduled 900 ms ago (now 1209630 ms), delaying
execution
Sep 20 10:28:34 node03 /usr/sbin/opensips[30302]: WARNING:core:timer_ticker:
timer task <tm-timer> already scheduled 1000 ms ago (now 1209630 ms), delaying
execution
Sep 20 10:28:34 node03 /usr/sbin/opensips[30302]: WARNING:core:utimer_ticker:
utimer task <tm-utimer> already scheduled 1000 ms ago (now 1209730 ms),
delaying execution
Sep 20 10:28:35 node03 /usr/sbin/opensips[30302]: WARNING:core:utimer_ticker:
utimer task <tm-utimer> already scheduled 1100 ms ago (now 1209830 ms),
delaying execution
[...]
Sep 20 10:29:02 node03 /usr/sbin/opensips[30302]: WARNING:core:utimer_ticker:
utimer task <tm-utimer> already scheduled 28760 ms ago (now 1237490 ms),
delaying execution
Sep 20 10:29:02 node03 /usr/sbin/opensips[30302]: WARNING:core:timer_ticker:
timer task <tm-timer> already scheduled 28860 ms ago (now 1237490 ms), delaying
execution
Sep 20 10:29:02 node03 /usr/sbin/opensips[30302]: WARNING:core:utimer_ticker:
utimer task <tm-utimer> already scheduled 28860 ms ago (now 1237590 ms),
delaying execution
Sep 20 10:29:02 node03 /usr/sbin/opensips[30302]: WARNING:core:utimer_ticker:
utimer task <tm-utimer> already scheduled 28960 ms ago (now 1237690 ms),
delaying execution
Sep 20 10:29:03 node03 /usr/sbin/opensips[30302]: WARNING:core:utimer_ticker:
utimer task <tm-utimer> already scheduled 29060 ms ago (now 1237790 ms),
delaying execution
Sep 20 10:29:03 node03 /usr/sbin/opensips[30302]: WARNING:core:utimer_ticker:
utimer task <tm-utimer> already scheduled 29160 ms ago (now 1237890 ms),
delaying execution
Sep 20 10:29:03 node03 /usr/sbin/opensips[30302]: WARNING:core:utimer_ticker:
utimer task <tm-utimer> already scheduled 29260 ms ago (now 1237990 ms),
delaying execution
Sep 20 10:29:03 node03 /usr/sbin/opensips[30302]: WARNING:core:utimer_ticker:
utimer task <tm-utimer> already scheduled 29360 ms ago (now 1238090 ms),
delaying execution
Sep 20 10:29:03 node03 /usr/sbin/opensips[30302]: WARNING:core:utimer_ticker:
utimer task <tm-utimer> already scheduled 29460 ms ago (now 1238190 ms),
delaying execution
Sep 20 10:29:03 node03 /usr/sbin/opensips[30302]: WARNING:core:utimer_ticker:
utimer task <tm-utimer> already scheduled 29560 ms ago (now 1238290 ms),
delaying execution
Sep 20 10:29:03 node03 /usr/sbin/opensips[30302]: WARNING:core:utimer_ticker:
utimer task <tm-utimer> already scheduled 29660 ms ago (now 1238390 ms),
delaying execution
Sep 20 10:29:03 node03 /usr/sbin/opensips[30302]: WARNING:core:utimer_ticker:
utimer task <tm-utimer> already scheduled 29750 ms ago (now 1238480 ms),
delaying execution
Sep 20 10:29:03 node03 /usr/sbin/opensips[30302]: WARNING:core:timer_ticker:
timer task <tm-timer> already scheduled 29850 ms ago (now 1238480 ms), delaying
execution
Sep 20 10:29:03 node03 /usr/sbin/opensips[30302]: WARNING:core:utimer_ticker:
utimer task <tm-utimer> already scheduled 29850 ms ago (now 1238580 ms),
delaying execution
On 17 Sep 2018, at 12:30, Dan Pascu wrote:
>
> I quite often find these warnings in syslog. They happen on an opensips 2.4
> installation that is completely idle (it does not process any messages at
> all, no registrations, no calls, no presence, nothing). Sometimes I see these
> warnings right after I start opensips, during the startup log, while the
> others happen randomly during the day.
>
> The excerpt below is what I got from opensips running for a few days and
> being completely idle the whole time:
>
> ./opensips[21850]: WARNING:core:handle_timer_job: timer job
> <dlg-options-pinger> has a 40000 us delay in execution
> ./opensips[21850]: WARNING:core:handle_timer_job: timer job
> <dlg-reinvite-pinger> has a 50000 us delay in execution
> ./opensips[21843]: WARNING:core:handle_timer_job: timer job <rls-notify> has
> a 40000 us delay in execution
> ./opensips[21850]: WARNING:core:handle_timer_job: timer job <nt-pinger> has a
> 40000 us delay in execution
> [...]
--
Dan
_______________________________________________
Users mailing list
[email protected]
http://lists.opensips.org/cgi-bin/mailman/listinfo/users
_______________________________________________
Users mailing list
[email protected]
http://lists.opensips.org/cgi-bin/mailman/listinfo/users
