[OpenSIPS-Users] OpenSIPs 3.0 Crash issue

Wed Jun 26 07:05:13 EDT 2019

Dear Team,

We have setup Opensips 3.0 stable version for stress testing. We are
invoking calls from SIPp to Opensips. We noticed after 600 CC with 10 CPS
Opensips crash. I have attached files for more details of DUMP.

Below is the call flow

(Leg A) SIPp (UAC)---> OpenSIPs(5070) ---> Freeswitch(5060)
(Leg B) Freeswitch(5060) --> OpenSIPs(5070) ---> SIPp (UAS)

OpenSIPs and Freeswitch is running on same machine with different ports.

As per our initial understanding it seems there is an issue with Memory.
Please help me on it,
--
Regards
Virendra Bhati
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.opensips.org/pipermail/users/attachments/20190626/d1e5305c/attachment-0001.html>
-------------- next part --------------
Jun 26 14:31:13 cloudconnect-PowerEdge-T30 /usr/local/sbin/opensips[24810]: Inside INVITE Call si=192.168.1.25 , sp=5080 , oP=udp ,avp=2
Jun 26 14:31:13 cloudconnect-PowerEdge-T30 /usr/local/sbin/opensips[24810]: call FS
Jun 26 14:31:13 cloudconnect-PowerEdge-T30 /usr/local/sbin/opensips[24810]: NOW rd=192.168.1.98 , rp=5060 , rP=udp, ru=sip:1046 at 192.168.1.98:5060 du=sip:192.168.1.98:5060
Jun 26 14:31:13 cloudconnect-PowerEdge-T30 /usr/local/sbin/opensips[24810]: new branch at sip:1046 at 192.168.1.98:5060
Jun 26 14:31:13 cloudconnect-PowerEdge-T30 /usr/local/sbin/opensips[24810]: inside =====> Handle_nat Reply Status:200 and User Agent: <null>
Jun 26 14:31:13 cloudconnect-PowerEdge-T30 /usr/local/sbin/opensips[24815]: inside =====> Handle_nat Reply Status:200 and User Agent: FreeSWITCH-mod_sofia/1.8.5~64bit
Jun 26 14:31:13 cloudconnect-PowerEdge-T30 /usr/local/sbin/opensips[24812]: Called [ACK] with [-2]
Jun 26 14:31:13 cloudconnect-PowerEdge-T30 /usr/local/sbin/opensips[24812]: Called [ACK] with [-2]
Jun 26 14:31:13 cloudconnect-PowerEdge-T30 /usr/local/sbin/opensips[24812]: inside =====> Handle_nat Reply Status:200 and User Agent: FreeSWITCH-mod_sofia/1.8.5~64bit
Jun 26 14:31:13 cloudconnect-PowerEdge-T30 /usr/local/sbin/opensips[24812]: ERROR:core:fm_malloc: not enough free shm memory (357200 bytes left, need 6712), please increase the "-m" command line parameter!
Jun 26 14:31:13 cloudconnect-PowerEdge-T30 /usr/local/sbin/opensips[24812]: INFO:core:fm_malloc: attempting defragmentation...
Jun 26 14:31:13 cloudconnect-PowerEdge-T30 /usr/local/sbin/opensips[24812]: INFO:core:fm_malloc: unable to alloc a big enough fragment!
Jun 26 14:31:13 cloudconnect-PowerEdge-T30 /usr/local/sbin/opensips[24812]: ERROR:tm:t_uac: short of cell shmem
Jun 26 14:31:13 cloudconnect-PowerEdge-T30 /usr/local/sbin/opensips[24812]: ERROR:pua:send_publish_int: failed to send PUBLISH
Jun 26 14:31:13 cloudconnect-PowerEdge-T30 /usr/local/sbin/opensips[24812]: ERROR:pua_dialoginfo:dialog_publish: sending publish failed for pres_uri [sip:1740 at 192.168.1.98:5061] to server [sip:192.168.1.25:5070]
Jun 26 14:31:13 cloudconnect-PowerEdge-T30 /usr/local/sbin/opensips[24812]: ERROR:core:fm_malloc: not enough free shm memory (356864 bytes left, need 6712), please increase the "-m" command line parameter!
Jun 26 14:31:13 cloudconnect-PowerEdge-T30 /usr/local/sbin/opensips[24812]: INFO:core:fm_malloc: attempting defragmentation...
Jun 26 14:31:13 cloudconnect-PowerEdge-T30 /usr/local/sbin/opensips[24812]: INFO:core:fm_malloc: unable to alloc a big enough fragment!
Jun 26 14:31:13 cloudconnect-PowerEdge-T30 /usr/local/sbin/opensips[24812]: ERROR:tm:t_uac: short of cell shmem
Jun 26 14:31:13 cloudconnect-PowerEdge-T30 /usr/local/sbin/opensips[24812]: ERROR:pua:send_publish_int: failed to send PUBLISH
Jun 26 14:31:13 cloudconnect-PowerEdge-T30 /usr/local/sbin/opensips[24812]: ERROR:pua_dialoginfo:dialog_publish: sending publish failed for pres_uri [sip:1240 at 192.168.1.25:5070] to server [sip:192.168.1.25:5070]
Jun 26 14:31:13 cloudconnect-PowerEdge-T30 /usr/local/sbin/opensips[24812]: Called [ACK] with [-2]
Jun 26 14:31:14 cloudconnect-PowerEdge-T30 /usr/local/sbin/opensips[24810]: inside =====> Handle_nat Reply Status:500 and User Agent: FreeSWITCH-mod_sofia/1.8.5~64bit
Jun 26 14:31:14 cloudconnect-PowerEdge-T30 /usr/local/sbin/opensips[24810]: Called [BYE] with [-1]
Jun 26 14:31:14 cloudconnect-PowerEdge-T30 /usr/local/sbin/opensips[24810]: Called [BYE] with [-1]
Jun 26 14:31:14 cloudconnect-PowerEdge-T30 /usr/local/sbin/opensips[24815]: inside =====> Handle_nat Reply Status:500 and User Agent: FreeSWITCH-mod_sofia/1.8.5~64bit
Jun 26 14:31:14 cloudconnect-PowerEdge-T30 /usr/local/sbin/opensips[24815]: Called [BYE] with [-1]
Jun 26 14:31:14 cloudconnect-PowerEdge-T30 /usr/local/sbin/opensips[24811]: inside =====> Handle_nat Reply Status:200 and User Agent: FreeSWITCH-mod_sofia/1.8.5~64bit
Jun 26 14:31:14 cloudconnect-PowerEdge-T30 /usr/local/sbin/opensips[24810]: Called [BYE] with [-1]
Jun 26 14:31:14 cloudconnect-PowerEdge-T30 /usr/local/sbin/opensips[24810]: ERROR:core:fm_malloc: not enough free shm memory (349984 bytes left, need 6712), please increase the "-m" command line parameter!
Jun 26 14:31:14 cloudconnect-PowerEdge-T30 /usr/local/sbin/opensips[24810]: INFO:core:fm_malloc: attempting defragmentation...
Jun 26 14:31:14 cloudconnect-PowerEdge-T30 /usr/local/sbin/opensips[24810]: INFO:core:fm_malloc: unable to alloc a big enough fragment!
Jun 26 14:31:14 cloudconnect-PowerEdge-T30 /usr/local/sbin/opensips[24810]: ERROR:tm:new_t: out of mem
Jun 26 14:31:14 cloudconnect-PowerEdge-T30 /usr/local/sbin/opensips[24810]: ERROR:tm:t_newtran: new_t failed
Jun 26 14:31:14 cloudconnect-PowerEdge-T30 /usr/local/sbin/opensips[24810]: Called [BYE] with [-1]
Jun 26 14:31:14 cloudconnect-PowerEdge-T30 /usr/local/sbin/opensips[24810]: Called [BYE] with [-1]
Jun 26 14:31:14 cloudconnect-PowerEdge-T30 /usr/local/sbin/opensips[24810]: inside =====> Handle_nat Reply Status:500 and User Agent: FreeSWITCH-mod_sofia/1.8.5~64bit
Jun 26 14:31:14 cloudconnect-PowerEdge-T30 /usr/local/sbin/opensips[24810]: Called [BYE] with [-1]
Jun 26 14:31:14 cloudconnect-PowerEdge-T30 /usr/local/sbin/opensips[24809]: Called [BYE] with [-1]
Jun 26 14:31:14 cloudconnect-PowerEdge-T30 /usr/local/sbin/opensips[24810]: Called [BYE] with [-1]
Jun 26 14:31:14 cloudconnect-PowerEdge-T30 /usr/local/sbin/opensips[24809]: Called [BYE] with [-1]
Jun 26 14:31:14 cloudconnect-PowerEdge-T30 /usr/local/sbin/opensips[24815]: Called [BYE] with [-1]
Jun 26 14:31:14 cloudconnect-PowerEdge-T30 /usr/local/sbin/opensips[24814]: Called [BYE] with [-1]
Jun 26 14:31:14 cloudconnect-PowerEdge-T30 /usr/local/sbin/opensips[24814]: message repeated 2 times: [ Called [BYE] with [-1]]
Jun 26 14:31:14 cloudconnect-PowerEdge-T30 /usr/local/sbin/opensips[24810]: inside =====> Handle_nat Reply Status:100 and User Agent: FreeSWITCH-mod_sofia/1.8.5~64bit
Jun 26 14:31:14 cloudconnect-PowerEdge-T30 /usr/local/sbin/opensips[24809]: Get group is 2 and AVP group 2
Jun 26 14:31:14 cloudconnect-PowerEdge-T30 /usr/local/sbin/opensips[24809]: Inside INVITE Call rd=192.168.1.25 , rp=5070 , rP=udp, ru=sip:1051 at 192.168.1.25:5070 du=<null>
Jun 26 14:31:14 cloudconnect-PowerEdge-T30 /usr/local/sbin/opensips[24809]: Inside INVITE Call si=192.168.1.25 , sp=5080 , oP=udp ,avp=2
Jun 26 14:31:14 cloudconnect-PowerEdge-T30 /usr/local/sbin/opensips[24809]: call FS
Jun 26 14:31:14 cloudconnect-PowerEdge-T30 /usr/local/sbin/opensips[24809]: NOW rd=192.168.1.98 , rp=5060 , rP=udp, ru=sip:1051 at 192.168.1.98:5060 du=sip:192.168.1.98:5060
Jun 26 14:31:14 cloudconnect-PowerEdge-T30 /usr/local/sbin/opensips[24809]: ERROR:core:fm_malloc: not enough free shm memory (345696 bytes left, need 6712), please increase the "-m" command line parameter!
Jun 26 14:31:14 cloudconnect-PowerEdge-T30 /usr/local/sbin/opensips[24809]: INFO:core:fm_malloc: attempting defragmentation...
Jun 26 14:31:14 cloudconnect-PowerEdge-T30 /usr/local/sbin/opensips[24809]: INFO:core:fm_malloc: unable to alloc a big enough fragment!
Jun 26 14:31:14 cloudconnect-PowerEdge-T30 /usr/local/sbin/opensips[24809]: ERROR:tm:new_t: out of mem
Jun 26 14:31:14 cloudconnect-PowerEdge-T30 /usr/local/sbin/opensips[24809]: ERROR:tm:t_newtran: new_t failed
Jun 26 14:31:14 cloudconnect-PowerEdge-T30 /usr/local/sbin/opensips[24810]: Called [BYE] with [-1]
Jun 26 14:31:14 cloudconnect-PowerEdge-T30 /usr/local/sbin/opensips[24811]: Called [BYE] with [-1]
Jun 26 14:31:14 cloudconnect-PowerEdge-T30 /usr/local/sbin/opensips[24808]: WARNING:core:timer_ticker: timer task <ul-timer> already scheduled 540050 ms ago (now 660370 ms), delaying execution
Jun 26 14:31:14 cloudconnect-PowerEdge-T30 /usr/local/sbin/opensips[24810]: inside =====> Handle_nat Reply Status:487 and User Agent: FreeSWITCH-mod_sofia/1.8.5~64bit
Jun 26 14:31:14 cloudconnect-PowerEdge-T30 /usr/local/sbin/opensips[24810]: inside =====> Handle_nat Reply Status:487 and User Agent: FreeSWITCH-mod_sofia/1.8.5~64bit
Jun 26 14:31:14 cloudconnect-PowerEdge-T30 /usr/local/sbin/opensips[24818]: CRITICAL:core:sig_usr: segfault in process pid: 24818, id: 14
Jun 26 14:31:14 cloudconnect-PowerEdge-T30 /usr/local/sbin/opensips[24810]: Called [BYE] with [-1]
Jun 26 14:31:14 cloudconnect-PowerEdge-T30 /usr/local/sbin/opensips[24810]: message repeated 2 times: [ Called [BYE] with [-1]]
Jun 26 14:31:14 cloudconnect-PowerEdge-T30 /usr/local/sbin/opensips[24812]: inside =====> Handle_nat Reply Status:200 and User Agent: FreeSWITCH-mod_sofia/1.8.5~64bit
Jun 26 14:31:14 cloudconnect-PowerEdge-T30 /usr/local/sbin/opensips[24813]: Called [BYE] with [-1]
Jun 26 14:31:14 cloudconnect-PowerEdge-T30 /usr/local/sbin/opensips[24811]: inside =====> Handle_nat Reply Status:100 and User Agent: FreeSWITCH-mod_sofia/1.8.5~64bit
Jun 26 14:31:14 cloudconnect-PowerEdge-T30 /usr/local/sbin/opensips[24811]: Called [BYE] with [-1]
Jun 26 14:31:14 cloudconnect-PowerEdge-T30 /usr/local/sbin/opensips[24808]: WARNING:core:utimer_ticker: utimer task <tm-utimer> already scheduled 100 ms ago (now 660570 ms), delaying execution
Jun 26 14:31:14 cloudconnect-PowerEdge-T30 /usr/local/sbin/opensips[24804]: INFO:core:handle_sigs: child process 24818 exited by a signal 11
Jun 26 14:31:14 cloudconnect-PowerEdge-T30 /usr/local/sbin/opensips[24804]: INFO:core:handle_sigs: core was generated
Jun 26 14:31:14 cloudconnect-PowerEdge-T30 /usr/local/sbin/opensips[24804]: INFO:core:handle_sigs: terminating due to SIGCHLD
Jun 26 14:31:14 cloudconnect-PowerEdge-T30 /usr/local/sbin/opensips[24808]: INFO:core:sig_usr: signal 15 received
Jun 26 14:31:14 cloudconnect-PowerEdge-T30 /usr/local/sbin/opensips[24805]: INFO:core:sig_usr: signal 15 received
Jun 26 14:31:14 cloudconnect-PowerEdge-T30 /usr/local/sbin/opensips[24807]: INFO:core:sig_usr: signal 15 received
Jun 26 14:31:14 cloudconnect-PowerEdge-T30 /usr/local/sbin/opensips[24804]: INFO:core:shutdown_opensips: process 1(24805) [MI FIFO] terminated, still waiting for 16 more
Jun 26 14:31:14 cloudconnect-PowerEdge-T30 /usr/local/sbin/opensips[24804]: INFO:core:shutdown_opensips: process 2(24806) [FS Manager] terminated, still waiting for 15 more
Jun 26 14:31:14 cloudconnect-PowerEdge-T30 /usr/local/sbin/opensips[24804]: INFO:core:shutdown_opensips: process 16(24820) [TCP receiver] terminated, still waiting for 14 more
Jun 26 14:31:14 cloudconnect-PowerEdge-T30 /usr/local/sbin/opensips[24804]: INFO:core:shutdown_opensips: process 3(24807) [time_keeper] terminated, still waiting for 13 more
Jun 26 14:31:14 cloudconnect-PowerEdge-T30 /usr/local/sbin/opensips[24804]: INFO:core:shutdown_opensips: process 4(24808) [timer] terminated, still waiting for 12 more
Jun 26 14:31:14 cloudconnect-PowerEdge-T30 /usr/local/sbin/opensips[24804]: INFO:core:shutdown_opensips: process 19(24824) [TCP main] terminated, still waiting for 11 more
Jun 26 14:31:14 cloudconnect-PowerEdge-T30 /usr/local/sbin/opensips[24804]: INFO:core:shutdown_opensips: process 17(24821) [Timer handler] terminated, still waiting for 10 more
Jun 26 14:31:14 cloudconnect-PowerEdge-T30 /usr/local/sbin/opensips[24804]: INFO:core:shutdown_opensips: process 7(24811) [SIP receiver udp:192.168.1.25:5070] terminated, still waiting for 9 more
Jun 26 14:31:14 cloudconnect-PowerEdge-T30 /usr/local/sbin/opensips[24804]: INFO:core:shutdown_opensips: process 18(24822) [Timer handler] terminated, still waiting for 8 more
Jun 26 14:31:19 cloudconnect-PowerEdge-T30 /usr/local/sbin/opensips[24804]: INFO:core:cleanup: cleanup
Jun 26 14:31:19 cloudconnect-PowerEdge-T30 /usr/local/sbin/opensips[24804]: INFO:db_mysql:switch_state_to_disconnected: disconnect event for 0x7f7525cf4550
Jun 26 14:31:19 cloudconnect-PowerEdge-T30 /usr/local/sbin/opensips[24804]: INFO:db_mysql:reset_all_statements: resetting all statements on connection: (0x7f7525cf5198) 0x7f7525cf4550
Jun 26 14:31:19 cloudconnect-PowerEdge-T30 /usr/local/sbin/opensips[24804]: INFO:db_mysql:connect_with_retry: re-connected successful for 0x7f7525cf4550
Jun 26 14:31:44 cloudconnect-PowerEdge-T30 /usr/local/sbin/opensips[24804]: NOTICE:presence:destroy: destroy module ...
Jun 26 14:31:55 cloudconnect-PowerEdge-T30 /usr/local/sbin/opensips[24804]: CRITICAL:core:fm_free: freeing already freed shm pointer (0x7f752506e138), first free: (null): #001(0) - aborting!

-------------- next part --------------
A non-text attachment was scrubbed...
Name: opensips_BT_FULL
Type: application/octet-stream
Size: 17626 bytes
Desc: not available
URL: <http://lists.opensips.org/pipermail/users/attachments/20190626/d1e5305c/attachment-0001.obj>