[OpenSIPS-Users] utimer_ticker warning in opensips 3.2
Sasmita Panda
spanda at 3clogic.com
Mon May 27 09:46:19 UTC 2024
Hi ,
I am just facing the same issue again .
/usr/local/sbin/opensips[3443]: CRITICAL:core:fm_free: freeing already
freed shm pointer (0x7f3a59ddb4a0), first free: (null): (null)(0) -
aborting!
whenever I am starting opensips this is the last line I am getting in the
logs and it wont listen on the specified port .
As earlier suggested I was trying to run a trap with opensips-cli , but I
am facing an issue with that . It says the trap module is not loaded .
How do I load the trap module of opesnips-cli specifically ?
Please help . This is a kind of blocker for me .
*Thanks & Regards*
*Sasmita Panda*
*Senior Network Testing and Software Engineer*
*3CLogic , ph:07827611765*
On Thu, Mar 21, 2024 at 10:01 PM Bogdan-Andrei Iancu <bogdan at opensips.org>
wrote:
> IF
>
> (a) it crashes, try to get a backtrace
>
> (b) it block on starting, try to do a "trap" via opensips-cli
>
> Regards,
>
> Bogdan-Andrei Iancu
>
> OpenSIPS Founder and Developer
> https://www.opensips-solutions.com
> https://www.siphub.com
>
> On 21.03.2024 08:24, Sasmita Panda wrote:
>
> 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/20240527/1d89cb31/attachment-0001.html>
More information about the Users
mailing list