[OpenSIPS-Users] utimer_ticker warning in opensips 3.2

Sasmita Panda spanda at 3clogic.com
Thu Mar 21 06:24:12 UTC 2024


Sometimes it crashes and sometimes while starting I get the warings of the
timer .  Same config  shows different issues .



*Thanks & Regards*
*Sasmita Panda*
*Senior Network Testing and Software Engineer*
*3CLogic , ph:07827611765*


On Wed, Mar 20, 2024 at 6:45 PM Bogdan-Andrei Iancu <bogdan at opensips.org>
wrote:

> Hi,
>
> How the two reports fit together here ? there are completely separate
> experiences on different runs?? or if you start opensips first you get the
> warnings and later it crashes ??
> For the crash part, I see a core file was generated - could you extract
> the backtrace and post here ? (see
> https://opensips.org/Documentation/TroubleShooting-Crash)
>
> Regards
>
> Bogdan-Andrei Iancu
>
> OpenSIPS Founder and Developer
>   https://www.opensips-solutions.com
>   https://www.siphub.com
>
> On 11.03.2024 15:04, Sasmita Panda wrote:
>
> Any update on this ?
>
>
> *Thanks & Regards*
> *Sasmita Panda*
> *Senior Network Testing and Software Engineer*
> *3CLogic , ph:07827611765*
>
>
> On Mon, Mar 11, 2024 at 12:03 PM Sasmita Panda <spanda at 3clogic.com> wrote:
>
>> With the same server configuration and opensips version I am getting
>> below error as well .
>>
>> CRITICAL:core:fm_free: freeing already freed shm pointer
>> (0x7fc110e0b408), first free: (null): (null)(0) - aborting!
>>
>>  /usr/local/sbin/opensips[215171]: INFO:core:handle_sigs: child process
>> 215185 exited by a signal 6
>>  /usr/local/sbin/opensips[215171]: INFO:core:handle_sigs: core was
>> generated
>>  /usr/local/sbin/opensips[215171]: INFO:core:handle_sigs: terminating
>> due to SIGCHLD
>>  /usr/local/sbin/opensips[215172]: Memory status (pkg):
>>  /usr/local/sbin/opensips[215172]: fm_status (0x7fc2907ff010):
>>  /usr/local/sbin/opensips[215174]: INFO:core:sig_usr: signal 15 received
>>  /usr/local/sbin/opensips[215172]: heap size= 33554432
>>  /usr/local/sbin/opensips[215174]: Memory status (pkg):
>>  /usr/local/sbin/opensips[215172]: used= 3710048, used+overhead=3801344,
>> free=29844384
>>  /usr/local/sbin/opensips[215174]: fm_status (0x7fc2907ff010):
>>  /usr/local/sbin/opensips[215172]: max used (+overhead)= 3801344
>>  /usr/local/sbin/opensips[215174]: heap size= 33554432
>>  /usr/local/sbin/opensips[215172]: dumping free list:
>>  /usr/local/sbin/opensips[215174]: used= 229752, used+overhead=318936,
>> free=33324680
>>  /usr/local/sbin/opensips[215172]: hash =   1 fragments no.:     1,
>> unused:     0#012#011#011 bucket size:         8 -         8 (first
>> 8)
>>  /usr/local/sbin/opensips[215174]: max used (+overhead)= 385792
>>  /usr/local/sbin/opensips[215174]: dumping free list:
>>  /usr/local/sbin/opensips[215172]: hash =  18 fragments no.:     1,
>> unused:     0#012#011#011 bucket size:       144 -       144 (first
>> 144)
>>  /usr/local/sbin/opensips[215174]: hash =   7 fragments no.:   139,
>> unused:     0#012#011#011 bucket size:        56 -        56 (first
>>  56)
>>  /usr/local/sbin/opensips[215172]: hash = 2059 fragments no.:     1,
>> unused:     0#012#011#011 bucket size:  16777216 -  33554432 (first
>>  29752936)
>>  /usr/local/sbin/opensips[215174]: hash =  13 fragments no.:    37,
>> unused:     0#012#011#011 bucket size:       104 -       104 (first
>> 104)
>>  /usr/local/sbin/opensips[215172]: TOTAL:      3 free fragments =
>> 29753088 free bytes
>>  /usr/local/sbin/opensips[215172]: TOTAL: 48 overhead
>>  /usr/local/sbin/opensips[215174]: hash =  16 fragments no.:    61,
>> unused:     0#012#011#011 bucket size:       128 -       128 (first
>> 128)
>>  /usr/local/sbin/opensips[215172]: -----------------------------
>>  /usr/local/sbin/opensips[215174]: hash =  31 fragments no.:   152,
>> unused:     0#012#011#011 bucket size:       248 -       248 (first
>> 248)
>>  /usr/local/sbin/opensips[215174]: hash =  68 fragments no.:    16,
>> unused:     0#012#011#011 bucket size:       544 -       544 (first
>> 544)
>>  /usr/local/sbin/opensips[215174]: hash = 105 fragments no.:     1,
>> unused:     0#012#011#011 bucket size:       840 -       840 (first
>> 840)
>>  /usr/local/sbin/opensips[215174]: hash = 2059 fragments no.:     1,
>> unused:     0#012#011#011 bucket size:  16777216 -  33554432 (first
>>  33168816)
>>  /usr/local/sbin/opensips[215174]: TOTAL:    407 free fragments =
>> 33235496 free bytes
>>  /usr/local/sbin/opensips[215174]: TOTAL: 48 overhead
>>  /usr/local/sbin/opensips[215174]: -----------------------------
>>  /usr/local/sbin/opensips[215176]: Memory status (pkg):
>>  /usr/local/sbin/opensips[215176]: fm_status (0x7fc2907ff010):
>>  /usr/local/sbin/opensips[215176]: heap size= 33554432
>>  /usr/local/sbin/opensips[215176]: used= 3705480, used+overhead=3796584,
>> free=29848952
>>  /usr/local/sbin/opensips[215176]: max used (+overhead)= 3798064
>>  /usr/local/sbin/opensips[215176]: dumping free list:
>>  /usr/local/sbin/opensips[215176]: hash =   2 fragments no.:     2,
>> unused:     0#012#011#011 bucket size:        16 -        16 (first
>>  16)
>>  /usr/local/sbin/opensips[215176]: hash =   3 fragments no.:     1,
>> unused:     0#012#011#011 bucket size:        24 -        24 (first
>>  24)
>>  /usr/local/sbin/opensips[215176]: hash =  16 fragments no.:     1,
>> unused:     0#012#011#011 bucket size:       128 -       128 (first
>> 128)
>>  /usr/local/sbin/opensips[215175]: Memory status (pkg):
>>  /usr/local/sbin/opensips[215175]: fm_status (0x7fc2907ff010):
>>  /usr/local/sbin/opensips[215175]: heap size= 33554432
>>  /usr/local/sbin/opensips[215176]: hash = 2059 fragments no.:     1,
>> unused:     0#012#011#011 bucket size:  16777216 -  33554432 (first
>>  29757664)
>>  /usr/local/sbin/opensips[215175]: used= 3705480, used+overhead=3796584,
>> free=29848952
>>  /usr/local/sbin/opensips[215176]: TOTAL:      5 free fragments =
>> 29757848 free bytes
>>  /usr/local/sbin/opensips[215175]: max used (+overhead)= 3798064
>>  /usr/local/sbin/opensips[215176]: TOTAL: 48 overhead
>>  /usr/local/sbin/opensips[215176]: -----------------------------
>>  /usr/local/sbin/opensips[215175]: dumping free list:
>>  /usr/local/sbin/opensips[215175]: hash =   2 fragments no.:     2,
>> unused:     0#012#011#011 bucket size:        16 -        16 (first
>>  16)
>>  /usr/local/sbin/opensips[215175]: hash =   3 fragments no.:     1,
>> unused:     0#012#011#011 bucket size:        24 -        24 (first
>>  24)
>>  /usr/local/sbin/opensips[215175]: hash =  16 fragments no.:     1,
>> unused:     0#012#011#011 bucket size:       128 -       128 (first
>> 128)
>>  /usr/local/sbin/opensips[215175]: hash = 2059 fragments no.:     1,
>> unused:     0#012#011#011 bucket size:  16777216 -  33554432 (first
>>  29757664)
>>  /usr/local/sbin/opensips[215175]: TOTAL:      5 free fragments =
>> 29757848 free bytes
>>  /usr/local/sbin/opensips[215175]: TOTAL: 48 overhead
>>  /usr/local/sbin/opensips[215175]: -----------------------------
>>  /usr/local/sbin/opensips[215171]: INFO:core:shutdown_opensips: process
>> 3(215174) [timer] terminated, still waiting for 13 more
>>  /usr/local/sbin/opensips[215171]: INFO:core:shutdown_opensips: process
>> 4(215175) [SIP receiver udp:192.168.33.171:5060] terminated, still
>> waiting for 12 more
>>  /usr/local/sbin/opensips[215171]: INFO:core:shutdown_opensips: process
>> 5(215176) [SIP receiver udp:192.168.33.171:5060] terminated, still
>> waiting for 11 more
>>  /usr/local/sbin/opensips[215171]: INFO:core:shutdown_opensips: process
>> 1(215172) [MI FIFO] terminated, still waiting for 10 more
>>  /usr/local/sbin/opensips[215173]: INFO:core:sig_usr: signal 15 received
>>  /usr/local/sbin/opensips[215173]: Memory status (pkg):
>>  /usr/local/sbin/opensips[215173]: fm_status (0x7fc2907ff010):
>>  /usr/local/sbin/opensips[215173]: heap size= 33554432
>>  /usr/local/sbin/opensips[215173]: used= 229752, used+overhead=318936,
>> free=33324680
>>  /usr/local/sbin/opensips[215173]: max used (+overhead)= 385792
>>  /usr/local/sbin/opensips[215173]: dumping free list:
>>  /usr/local/sbin/opensips[215173]: hash =   7 fragments no.:   139,
>> unused:     0#012#011#011 bucket size:        56 -        56 (first
>>  56)
>>  /usr/local/sbin/opensips[215173]: hash =  13 fragments no.:    37,
>> unused:     0#012#011#011 bucket size:       104 -       104 (first
>> 104)
>>  /usr/local/sbin/opensips[215173]: hash =  16 fragments no.:    61,
>> unused:     0#012#011#011 bucket size:       128 -       128 (first
>> 128)
>>  /usr/local/sbin/opensips[215173]: hash =  31 fragments no.:   152,
>> unused:     0#012#011#011 bucket size:       248 -       248 (first
>> 248)
>>  /usr/local/sbin/opensips[215173]: hash =  68 fragments no.:    16,
>> unused:     0#012#011#011 bucket size:       544 -       544 (first
>> 544)
>>  /usr/local/sbin/opensips[215173]: hash = 105 fragments no.:     1,
>> unused:     0#012#011#011 bucket size:       840 -       840 (first
>> 840)
>>  /usr/local/sbin/opensips[215173]: hash = 2059 fragments no.:     1,
>> unused:     0#012#011#011 bucket size:  16777216 -  33554432 (first
>>  33168816)
>>  /usr/local/sbin/opensips[215173]: TOTAL:    407 free fragments =
>> 33235496 free bytes
>>  /usr/local/sbin/opensips[215173]: TOTAL: 48 overhead
>>  /usr/local/sbin/opensips[215173]: -----------------------------
>>  /usr/local/sbin/opensips[215171]: INFO:core:shutdown_opensips: process
>> 2(215173) [time_keeper] terminated, still waiting for 9 more
>>  /usr/local/sbin/opensips[215171]: INFO:core:cleanup: cleanup
>>  /usr/local/sbin/opensips[215171]: CRITICAL:core:sig_alarm_abort: BUG -
>> shutdown timeout triggered, dying...
>>
>> *Why is the service crashing ? *
>>
>> *Thanks & Regards*
>> *Sasmita Panda*
>> *Senior Network Testing and Software Engineer*
>> *3CLogic , ph:07827611765*
>>
>>
>> On Mon, Mar 11, 2024 at 11:52 AM Sasmita Panda <spanda at 3clogic.com>
>> wrote:
>>
>>> Hi All ,
>>>
>>> Mar 11 05:57:02 ip-192-168-33-171 /usr/local/sbin/opensips[213843]:
>>> INFO:proto_ws:mod_init: initializing WebSocket protocol
>>> Mar 11 05:57:03 ip-192-168-33-171 /usr/local/sbin/opensips[213846]:
>>> WARNING:core:utimer_ticker: utimer task <tm-utimer> already scheduled 100
>>> ms ago (now 290 ms), delaying execution
>>> Mar 11 05:57:03 ip-192-168-33-171 /usr/local/sbin/opensips[213846]:
>>> WARNING:core:utimer_ticker: utimer task <tm-utimer> already scheduled 200
>>> ms ago (now 390 ms), delaying execution
>>> Mar 11 05:57:03 ip-192-168-33-171 /usr/local/sbin/opensips[213846]:
>>> WARNING:core:utimer_ticker: utimer task <tm-utimer> already scheduled 300
>>> ms ago (now 490 ms), delaying execution
>>> Mar 11 05:57:03 ip-192-168-33-171 /usr/local/sbin/opensips[213846]:
>>> WARNING:core:utimer_ticker: utimer task <tm-utimer> already scheduled 400
>>> ms ago (now 590 ms), delaying execution
>>> Mar 11 05:57:03 ip-192-168-33-171 /usr/local/sbin/opensips[213846]:
>>> WARNING:core:utimer_ticker: utimer task <tm-utimer> already scheduled 500
>>> ms ago (now 690 ms), delaying execution
>>> Mar 11 05:57:03 ip-192-168-33-171 /usr/local/sbin/opensips[213846]:
>>> WARNING:core:utimer_ticker: utimer task <tm-utimer> already scheduled 600
>>> ms ago (now 790 ms), delaying execution
>>> Mar 11 05:57:03 ip-192-168-33-171 /usr/local/sbin/opensips[213846]:
>>> WARNING:core:utimer_ticker: utimer task <tm-utimer> already scheduled 700
>>> ms ago (now 890 ms), delaying execution
>>> Mar 11 05:57:03 ip-192-168-33-171 /usr/local/sbin/opensips[213846]:
>>> WARNING:core:utimer_ticker: utimer task <tm-utimer> already scheduled 800
>>> ms ago (now 990 ms), delaying execution
>>> Mar 11 05:57:03 ip-192-168-33-171 /usr/local/sbin/opensips[213846]:
>>> WARNING:core:utimer_ticker: utimer task <tm-utimer> already scheduled 900
>>> ms ago (now 1090 ms), delaying execution
>>> Mar 11 05:57:03 ip-192-168-33-171 /usr/local/sbin/opensips[213846]:
>>> WARNING:core:utimer_ticker: utimer task <tm-utimer> already scheduled 1000
>>> ms ago (now 1190 ms), delaying execution
>>> Mar 11 05:57:04 ip-192-168-33-171 /usr/local/sbin/opensips[213846]:
>>> WARNING:core:utimer_ticker: utimer task <tm-utimer> already scheduled 1100
>>> ms ago (now 1290 ms), delaying execution
>>> Mar 11 05:57:04 ip-192-168-33-171 /usr/local/sbin/opensips[213846]:
>>> WARNING:core:utimer_ticker: utimer task <tm-utimer> already scheduled 1200
>>> ms ago (now 1390 ms), delaying execution
>>> Mar 11 05:57:04 ip-192-168-33-171 /usr/local/sbin/opensips[213846]:
>>> WARNING:core:utimer_ticker: utimer task <tm-utimer> already scheduled 1300
>>> ms ago (now 1490 ms), delaying execution
>>> Mar 11 05:57:04 ip-192-168-33-171 /usr/local/sbin/opensips[213846]:
>>> WARNING:core:utimer_ticker: utimer task <tm-utimer> already scheduled 1400
>>> ms ago (now 1590 ms), delaying execution
>>> Mar 11 05:57:04 ip-192-168-33-171 /usr/local/sbin/opensips[213846]:
>>> WARNING:core:utimer_ticker: utimer task <tm-utimer> already scheduled 1500
>>> ms ago (now 1690 ms), delaying execution
>>> Mar 11 05:57:04 ip-192-168-33-171 /usr/local/sbin/opensips[213846]:
>>> WARNING:core:utimer_ticker: utimer task <tm-utimer> already scheduled 1600
>>> ms ago (now 1790 ms), delaying execution
>>> Mar 11 05:57:04 ip-192-168-33-171 /usr/local/sbin/opensips[213846]:
>>> WARNING:core:utimer_ticker: utimer task <tm-utimer> already scheduled 1700
>>> ms ago (now 1890 ms), delaying execution
>>> Mar 11 05:57:04 ip-192-168-33-171 /usr/local/sbin/opensips[213846]:
>>> WARNING:core:utimer_ticker: utimer task <tm-utimer> already scheduled 1790
>>> ms ago (now 1980 ms), delaying execution
>>> Mar 11 05:57:04 ip-192-168-33-171 /usr/local/sbin/opensips[213846]:
>>> WARNING:core:timer_ticker: timer task <tm-timer> already scheduled 990 ms
>>> ago (now 1980 ms), delaying execution
>>>
>>> *What is this warning for? Whenever I am starting my openisps service
>>> this warning comes . Although the service seems like it's running but it's
>>> not listening on the socket exposed .  How to resolve this ?*
>>>
>>> */usr/local/sbin/opensips  -V*
>>> version: opensips 3.2.3 (x86_64/linux)
>>> flags: STATS: On, DISABLE_NAGLE, USE_MCAST, SHM_MMAP, PKG_MALLOC,
>>> Q_MALLOC, F_MALLOC, HP_MALLOC, DBG_MALLOC, FAST_LOCK-ADAPTIVE_WAIT
>>> ADAPTIVE_WAIT_LOOPS=1024, MAX_RECV_BUFFER_SIZE 262144, MAX_LISTEN 16,
>>> MAX_URI_SIZE 1024, BUF_SIZE 65535
>>> poll method support: poll, epoll, sigio_rt, select.
>>> svn revision: 3831:3878
>>> main.c compiled on 07:52:40 Mar 29 2023 with gcc 11
>>>
>>> *cat /etc/*release*
>>> Amazon Linux release 2023 (Amazon Linux)
>>> NAME="Amazon Linux"
>>> VERSION="2023"
>>> ID="amzn"
>>> ID_LIKE="fedora"
>>> VERSION_ID="2023"
>>> PLATFORM_ID="platform:al2023"
>>> PRETTY_NAME="Amazon Linux 2023"
>>> ANSI_COLOR="0;33"
>>> CPE_NAME="cpe:2.3:o:amazon:amazon_linux:2023"
>>> HOME_URL="https://aws.amazon.com/linux/"
>>> BUG_REPORT_URL="https://github.com/amazonlinux/amazon-linux-2023"
>>> SUPPORT_END="2028-03-01"
>>> Amazon Linux release 2023 (Amazon Linux)
>>>
>>>
>>> *Thanks & Regards*
>>> *Sasmita Panda*
>>> *Senior Network Testing and Software Engineer*
>>> *3CLogic , ph:07827611765*
>>>
>>
> _______________________________________________
> Users mailing listUsers at lists.opensips.orghttp://lists.opensips.org/cgi-bin/mailman/listinfo/users
>
>
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.opensips.org/pipermail/users/attachments/20240321/7d869966/attachment-0001.html>


More information about the Users mailing list