[OpenSIPS-Users] Fwd: opensips is restarting after call is finished
Neven Grzancic
neven at softnet.si
Fri Dec 8 11:35:02 UTC 2023
Dear Bogdan,
we tried following https://opensips.org/Documentation/TroubleShooting-Crash and trying different things, and even though the syslog shows that the core file was dumped:
Dec 8 12:25:13 sbc2 /usr/sbin/opensips[4363]: CRITICAL:core:sig_usr: segfault in process pid: 4363, id: 7
Dec 8 12:25:13 sbc2 kernel: [ 3394.269733] opensips[4363]: segfault at 0 ip 0000000000000000 sp 00007ffdc458f6a8 error 14 in opensips[55816fbd0000+1f000]
Dec 8 12:25:18 sbc2 mariadbd[922]: 2023-12-08 12:25:18 400 [Warning] Aborted connection 400 to db: 'opensips' user: 'opensips' host: 'localhost' (Got an error reading communication packets)
Dec 8 12:25:18 sbc2 /usr/sbin/opensips[4356]: INFO:core:handle_sigs: child process 4363 exited by a signal 11
Dec 8 12:25:18 sbc2 /usr/sbin/opensips[4356]: INFO:core:handle_sigs: core was generated
Dec 8 12:25:18 sbc2 /usr/sbin/opensips[4356]: INFO:core:handle_sigs: terminating due to SIGCHLD
Dec 8 12:25:18 sbc2 /usr/sbin/opensips[4359]: INFO:core:sig_usr: signal 15 received
Dec 8 12:25:18 sbc2 /usr/sbin/opensips[4360]: INFO:core:sig_usr: signal 15 received
the core does not get generated, or at least not in the directory provided via options at runtime (-w /tmp). The issue is always repeatable (the daemon crashes after every finished call), if there are more active calls at the moment of the crash, whose calls remain active and proceed normally until termination (which again causes a crash). We also tried enabling debug mode, but in that case the process does not start successfully and runs into a timeout. In any case, any additional help or suggestion on how to successfully generate the core dump would be much appreciated, as we seem to have ran into a wall here...
On 08.12.23 12:26, Simon Gajski wrote:
>
>
>
> -------- Posredovano sporočilo --------
> Zadeva: Re: [OpenSIPS-Users] opensips is restarting after call is finished
> Datum: Thu, 7 Dec 2023 17:52:37 +0200
> Od: Bogdan-Andrei Iancu <bogdan at opensips.org>
> Za: Simon Gajski <simon at softnet.si>, OpenSIPS users mailling list <users at lists.opensips.org>
>
>
>
> Hi Simon,
>
> Well, the log is very self explanatory:
> Dec 7 15:59:47 sbc2 /usr/sbin/opensips[28488]: INFO:core:handle_sigs: child process 28495 exited by a signal 11
> Dec 7 15:59:47 sbc2 /usr/sbin/opensips[28488]: INFO:core:handle_sigs: core was generated
> Dec 7 15:59:47 sbc2 /usr/sbin/opensips[28488]: INFO:core:handle_sigs: terminating due to SIGCHLD
>
> Or shortly, you opensips just crashed :). So see https://opensips.org/Documentation/TroubleShooting-Crash for how to report further.
>
> Regards,
>
> Bogdan-Andrei Iancu
>
> OpenSIPS Founder and Developer
> https://www.opensips-solutions.com
> https://www.siphub.com
>
> On 07.12.2023 17:17, Simon Gajski via Users wrote:
>>
>> Hi
>>
>> we are running opensips 3.4.2
>> on Ubuntu 22.04.3 LTS
>> and also use RTPengine Version: 10.5.0.0+0~mr10.5.0.0 git-master-74075f63
>>
>> Opensips acts as SBC with RTP engine enabled.
>>
>> Calls are working fine, however after each call is finished, bellow action happens.
>>
>> We had same problem with opensips 3.2 and Ubuntu 20. So we did upgrade to latest stable release, and it is the same.
>>
>> Is this opensips script configuration issue or a bug? And how could I fix it?
>>
>> Dec 7 15:59:47 sbc2 /usr/sbin/opensips[28488]: INFO:core:handle_sigs: child process 28495 exited by a signal 11
>> Dec 7 15:59:47 sbc2 /usr/sbin/opensips[28488]: INFO:core:handle_sigs: core was generated
>> Dec 7 15:59:47 sbc2 /usr/sbin/opensips[28488]: INFO:core:handle_sigs: terminating due to SIGCHLD
>> Dec 7 15:59:47 sbc2 /usr/sbin/opensips[28491]: INFO:core:sig_usr: signal 15 received
>> Dec 7 15:59:47 sbc2 /usr/sbin/opensips[28492]: INFO:core:sig_usr: signal 15 received
>> Dec 7 15:59:47 sbc2 /usr/sbin/opensips[28488]: INFO:core:shutdown_opensips: process 4(28492) [timer] terminated, still waiting for 16 more
>> Dec 7 15:59:47 sbc2 /usr/sbin/opensips[28488]: INFO:core:shutdown_opensips: process 18(28508) [TCP main] terminated, still waiting for 15 more
>> Dec 7 15:59:47 sbc2 /usr/sbin/opensips[28488]: INFO:core:shutdown_opensips: process 3(28491) [time_keeper] terminated, still waiting for 14 more
>> Dec 7 15:59:47 sbc2 /usr/sbin/opensips[28488]: INFO:core:shutdown_opensips: process 16(28504) [TCP receiver] terminated, still waiting for 13 more
>> Dec 7 15:59:47 sbc2 /usr/sbin/opensips[28488]: INFO:core:shutdown_opensips: process 2(28490) [MI FIFO] terminated, still waiting for 12 more
>> Dec 7 15:59:47 sbc2 /usr/sbin/opensips[28488]: INFO:core:shutdown_opensips: process 15(28503) [TCP receiver] terminated, still waiting for 11 more
>> Dec 7 15:59:47 sbc2 /usr/sbin/opensips[28488]: INFO:core:shutdown_opensips: process 14(28502) [TCP receiver] terminated, still waiting for 10 more
>> Dec 7 15:59:47 sbc2 /usr/sbin/opensips[28488]: INFO:core:shutdown_opensips: process 12(28500) [TCP receiver] terminated, still waiting for 9 more
>> Dec 7 15:59:47 sbc2 /usr/sbin/opensips[28488]: INFO:core:shutdown_opensips: process 1(28489) [HTTPD 127.0.0.1:8888] terminated, still waiting for 8 more
>> Dec 7 15:59:47 sbc2 /usr/sbin/opensips[28488]: INFO:core:shutdown_opensips: process 8(28496) [SIP receiver udp:213.253.120.65:5060] terminated, still waiting for 7 more
>> Dec 7 15:59:47 sbc2 /usr/sbin/opensips[28488]: INFO:core:shutdown_opensips: process 10(28498) [TCP receiver] terminated, still waiting for 6 more
>> Dec 7 15:59:47 sbc2 /usr/sbin/opensips[28488]: INFO:core:shutdown_opensips: process 13(28501) [TCP receiver] terminated, still waiting for 5 more
>> Dec 7 15:59:47 sbc2 /usr/sbin/opensips[28488]: INFO:core:shutdown_opensips: process 9(28497) [TCP receiver] terminated, still waiting for 4 more
>> Dec 7 15:59:47 sbc2 /usr/sbin/opensips[28488]: INFO:core:shutdown_opensips: process 11(28499) [TCP receiver] terminated, still waiting for 3 more
>> Dec 7 15:59:47 sbc2 /usr/sbin/opensips[28488]: INFO:core:shutdown_opensips: process 6(28494) [SIP receiver udp:213.253.120.65:5060] terminated, still waiting for 2 more
>> Dec 7 15:59:47 sbc2 /usr/sbin/opensips[28488]: INFO:core:shutdown_opensips: process 17(28507) [Timer handler] terminated, still waiting for 1 more
>> Dec 7 15:59:47 sbc2 /usr/sbin/opensips[28488]: INFO:core:shutdown_opensips: process 5(28493) [SIP receiver udp:213.253.120.65:5060] terminated, still waiting for 0 more
>> Dec 7 15:59:47 sbc2 /usr/sbin/opensips[28488]: INFO:core:cleanup: cleanup
>> Dec 7 15:59:47 sbc2 opensips: INFO:core:fix_poll_method: using epoll as the IO watch method (auto detected)
>> Dec 7 15:59:47 sbc2 /usr/sbin/opensips[31289]: NOTICE:core:main: version: opensips 3.4.2 (x86_64/linux)
>> Dec 7 15:59:47 sbc2 /usr/sbin/opensips[31289]: NOTICE:core:main: using 64 MB of shared memory, allocator: F_MALLOC
>> Dec 7 15:59:47 sbc2 /usr/sbin/opensips[31289]: NOTICE:core:main: using 4 MB of private process memory, allocator: F_MALLOC
>> Dec 7 15:59:47 sbc2 /usr/sbin/opensips[31289]: WARNING:core:init_reactor_size: shrinking reactor size from 262144 (autodetected via rlimit) to 10485 (limited by memory of 10% from 4Mb)
>> Dec 7 15:59:47 sbc2 /usr/sbin/opensips[31289]: WARNING:core:init_reactor_size: use 'open_files_limit' to enforce other limit or increase pkg memory
>> Dec 7 15:59:47 sbc2 /usr/sbin/opensips[31289]: INFO:core:init_reactor_size: reactor size 10485 (using up to 0.40Mb of memory per process)
>> Dec 7 15:59:47 sbc2 /usr/sbin/opensips[31289]: INFO:core:evi_publish_event: Registered event <E_CORE_THRESHOLD(1)>
>> Dec 7 15:59:47 sbc2 /usr/sbin/opensips[31289]: INFO:core:evi_publish_event: Registered event <E_CORE_SHM_THRESHOLD(2)>
>> Dec 7 15:59:47 sbc2 /usr/sbin/opensips[31289]: INFO:core:evi_publish_event: Registered event <E_CORE_PKG_THRESHOLD(3)>
>> Dec 7 15:59:47 sbc2 /usr/sbin/opensips[31289]: INFO:core:evi_publish_event: Registered event <E_CORE_PROC_AUTO_SCALE(4)>
>> Dec 7 15:59:47 sbc2 /usr/sbin/opensips[31289]: INFO:core:evi_publish_event: Registered event <E_CORE_TCP_DISCONNECT(5)>
>> Dec 7 15:59:47 sbc2 /usr/sbin/opensips[31289]: INFO:tm:mod_init: TM - initializing...
>> Dec 7 15:59:47 sbc2 /usr/sbin/opensips[31289]: INFO:sl:mod_init: Initializing StateLess engine
>> Dec 7 15:59:47 sbc2 /usr/sbin/opensips[31289]: NOTICE:signaling:mod_init: initializing module ...
>> Dec 7 15:59:47 sbc2 /usr/sbin/opensips[31289]: INFO:core:evi_publish_event: Registered event <E_MYSQL_CONNECTION(6)>
>> Dec 7 15:59:47 sbc2 /usr/sbin/opensips[31289]: INFO:dialog:mod_init: Dialog module - initializing
>> Dec 7 15:59:47 sbc2 /usr/sbin/opensips[31289]: INFO:core:evi_publish_event: Registered event <E_DLG_STATE_CHANGED(7)>
>> Dec 7 15:59:47 sbc2 /usr/sbin/opensips[31289]: INFO:rr:mod_init: rr - initializing
>> Dec 7 15:59:47 sbc2 /usr/sbin/opensips[31289]: INFO:uac:mod_init: initializing...
>> Dec 7 15:59:47 sbc2 /usr/sbin/opensips[31289]: INFO:acc:mod_init: initializing...
>> Dec 7 15:59:47 sbc2 /usr/sbin/opensips[31289]: INFO:core:evi_publish_event: Registered event <E_ACC_EVENT(8)>
>> Dec 7 15:59:47 sbc2 /usr/sbin/opensips[31289]: INFO:core:evi_publish_event: Registered event <E_ACC_CDR(9)>
>> Dec 7 15:59:47 sbc2 /usr/sbin/opensips[31289]: INFO:core:evi_publish_event: Registered event <E_ACC_MISSED_EVENT(10)>
>> Dec 7 15:59:47 sbc2 /usr/sbin/opensips[31289]: INFO:textops:mod_init: initializing...
>> Dec 7 15:59:47 sbc2 /usr/sbin/opensips[31289]: INFO:maxfwd:mod_init: initializing...
>> Dec 7 15:59:47 sbc2 /usr/sbin/opensips[31289]: INFO:sipmsgops:mod_init: initializing...
>> Dec 7 15:59:47 sbc2 /usr/sbin/opensips[31289]: INFO:avpops:avpops_init: initializing...
>> Dec 7 15:59:47 sbc2 /usr/sbin/opensips[31289]: INFO:drouting:dr_init: dynamic routing - initializing
>> Dec 7 15:59:47 sbc2 /usr/sbin/opensips[31289]: INFO:drouting:init_prefix_tree: counted 10 possible chars under a node
>> Dec 7 15:59:47 sbc2 /usr/sbin/opensips[31289]: INFO:core:evi_publish_event: Registered event <E_DROUTING_STATUS(11)>
>> Dec 7 15:59:47 sbc2 /usr/sbin/opensips[31289]: INFO:permissions:mod_init: default allow file (/etc/opensips/permissions.allow) not found => empty rule set
>> Dec 7 15:59:47 sbc2 /usr/sbin/opensips[31289]: INFO:permissions:mod_init: default deny file (/etc/opensips/permissions.deny) not found => empty rule set
>> Dec 7 15:59:47 sbc2 /usr/sbin/opensips[31289]: INFO:regex:mod_init: initializing module...
>> Dec 7 15:59:47 sbc2 /usr/sbin/opensips[31289]: NOTICE:regex:mod_init: 'file' parameter is not set, group matching disabled
>> Dec 7 15:59:47 sbc2 /usr/sbin/opensips[31289]: INFO:topology_hiding:mod_init: initializing...
>> Dec 7 15:59:47 sbc2 /usr/sbin/opensips[31289]: INFO:core:evi_publish_event: Registered event <E_RTPENGINE_STATUS(12)>
>> Dec 7 15:59:47 sbc2 /usr/sbin/opensips[31289]: INFO:userblacklist:mod_init: initializing ...
>> Dec 7 15:59:47 sbc2 /usr/sbin/opensips[31289]: INFO:userblacklist:mod_init: finished initializing
>> Dec 7 15:59:47 sbc2 /usr/sbin/opensips[31289]: INFO:dialplan:mod_init: initializing module...
>> Dec 7 15:59:47 sbc2 /usr/sbin/opensips[31289]: INFO:core:mod_init: initializing UDP-plain protocol
>> Dec 7 15:59:47 sbc2 /usr/sbin/opensips[31289]: INFO:core:mod_init: initializing TCP-plain protocol
>> Dec 7 15:59:47 sbc2 /usr/sbin/opensips[31289]: INFO:core:evi_publish_event: Registered event <E_CORE_LOG(13)>
>> Dec 7 15:59:47 sbc2 /usr/sbin/opensips[31290]: INFO:rtpengine:rtpe_test: rtp proxy <udp:127.0.0.1:2223> found, support for it enabled
>> Dec 7 15:59:47 sbc2 /usr/sbin/opensips[31291]: INFO:rtpengine:rtpe_test: rtp proxy <udp:127.0.0.1:2223> found, support for it enabled
>> Dec 7 15:59:48 sbc2 /usr/sbin/opensips[31294]: INFO:rtpengine:rtpe_test: rtp proxy <udp:127.0.0.1:2223> found, support for it enabled
>> Dec 7 15:59:48 sbc2 /usr/sbin/opensips[31294]: INFO:drouting:dr_reload_data_head: loading drouting data!
>> Dec 7 15:59:48 sbc2 /usr/sbin/opensips[31295]: INFO:rtpengine:rtpe_test: rtp proxy <udp:127.0.0.1:2223> found, support for it enabled
>> Dec 7 15:59:48 sbc2 /usr/sbin/opensips[31296]: INFO:rtpengine:rtpe_test: rtp proxy <udp:127.0.0.1:2223> found, support for it enabled
>> Dec 7 15:59:48 sbc2 /usr/sbin/opensips[31297]: INFO:rtpengine:rtpe_test: rtp proxy <udp:127.0.0.1:2223> found, support for it enabled
>> Dec 7 15:59:48 sbc2 /usr/sbin/opensips[31298]: INFO:rtpengine:rtpe_test: rtp proxy <udp:127.0.0.1:2223> found, support for it enabled
>> Dec 7 15:59:48 sbc2 /usr/sbin/opensips[31299]: INFO:rtpengine:rtpe_test: rtp proxy <udp:127.0.0.1:2223> found, support for it enabled
>> Dec 7 15:59:48 sbc2 /usr/sbin/opensips[31300]: INFO:rtpengine:rtpe_test: rtp proxy <udp:127.0.0.1:2223> found, support for it enabled
>> Dec 7 15:59:48 sbc2 /usr/sbin/opensips[31301]: INFO:rtpengine:rtpe_test: rtp proxy <udp:127.0.0.1:2223> found, support for it enabled
>> Dec 7 15:59:48 sbc2 /usr/sbin/opensips[31302]: INFO:rtpengine:rtpe_test: rtp proxy <udp:127.0.0.1:2223> found, support for it enabled
>> Dec 7 15:59:48 sbc2 /usr/sbin/opensips[31303]: INFO:rtpengine:rtpe_test: rtp proxy <udp:127.0.0.1:2223> found, support for it enabled
>> Dec 7 15:59:48 sbc2 /usr/sbin/opensips[31304]: INFO:rtpengine:rtpe_test: rtp proxy <udp:127.0.0.1:2223> found, support for it enabled
>> Dec 7 15:59:48 sbc2 /usr/sbin/opensips[31305]: INFO:rtpengine:rtpe_test: rtp proxy <udp:127.0.0.1:2223> found, support for it enabled
>> Dec 7 15:59:48 sbc2 /usr/sbin/opensips[31306]: INFO:rtpengine:rtpe_test: rtp proxy <udp:127.0.0.1:2223> found, support for it enabled
>> Dec 7 15:59:48 sbc2 opensips: INFO:core:daemonize: pre-daemon process exiting with 0
>>
>> Thanks for all tips.
>>
>> BR
>> Simon
>>
>>
>> _______________________________________________
>> Users mailing list
>> Users at lists.opensips.org
>> http://lists.opensips.org/cgi-bin/mailman/listinfo/users
>
--
Best regards / Lep pozdrav
Neven Grzancic, dipl.inž.el.(UN)
techsupport - systems administration & networking
-----------------------------------------------------------------------
Softnet d.o.o. tel: +386 1 8100 100 | the quieter you
Borovec 2 direct: +386 1 8100 107 | become, the more you
1236 Trzin fax: +386 1 8100 101 | are able to hear
-----------------------------------------------------------------------
More information about the Users
mailing list