Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

[CRASH] opensips crashes on timer route while firing curl request #2195

Closed
imdrpn opened this issue Aug 4, 2020 · 11 comments
Closed

[CRASH] opensips crashes on timer route while firing curl request #2195

imdrpn opened this issue Aug 4, 2020 · 11 comments
Labels
stale

Comments

@imdrpn
Copy link

imdrpn commented Aug 4, 2020 •
edited
Loading

opensips version :
version: opensips 2.4.7 (x86_64/linux)
flags: STATS: On, DISABLE_NAGLE, USE_MCAST, SHM_MMAP, PKG_MALLOC, F_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.
git revision: 9e1fcc9
main.c compiled on 10:27:49 Feb 3 2020 with gcc 4.8.5

usage : i have used timer route which is executing every second and in this timer route i am firing curl request , using rest_post as below :
(from api side i have developed function for call scheduling and if any call hangup time is current time or less than current time then i am sending request to hangup current call by call_id using dlg_end_dlg xmlrpc command . )

rest_client.so

loadmodule "rest_client.so"
modparam("rest_client", "curl_timeout", 60)
modparam("rest_client", "connection_timeout", 60)

timer_route[call_schedule_hangup,1] {

$avp(current_time)=$Ts;
xlog("L_INFO"," [TIMER_ROUTE] CURRENT TIME IS : $Ts $time(%Y-%m-%d %H:%M:%S) <<<<====");
$var(body_type)="application/x-www-form-urlencoded";

  $var(rc_hangup) = rest_post("https://XXXweb.YYYY.co.ZZZ/XXXX-billing/billing_api.php","action=call_select","$var(body_type)", "$var(body_schedule)","$var(ct)","$var(rcode_schedule)");  
        xlog("L_INFO","[timer_route][call_schedule_hangup] HTTP BODY RESPONSE IS : $var(body_schedule)  <<<==");
        xlog("L_INFO","[timer_route][call_schedule_hangup] content type header of response IS : $var(ct)  <<<==");
        xlog("L_INFO","[timer_route][call_schedule_hangup] STATUS CODE OF HTTP RESPONSE  : $var(rcode_schedule) <<<==");
        if ($var(rc_schedule) < 0) {
            xlog("L_INFO","[timer_route][call_schedule_hangup] rest_post() failed with $var(rc_schedule)");
            #send_reply(500, "Server Internal Error 1");
            exit;
        }

        if ($var(rcode_schedule) != 200) {
            xlog("L_INFO","[timer_route][call_schedule_hangup]rest_post() rcode=$var(rcode_schedule)");
            #send_reply(500, "Server Internal Error 2");
            exit;
        }

}

CORE : Copyright (C) 2013 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later http://gnu.org/licenses/gpl.html
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law. Type "show copying"
and "show warranty" for details.
This GDB was configured as "x86_64-redhat-linux-gnu".
For bug reporting instructions, please see:
http://www.gnu.org/software/gdb/bugs/...
Reading symbols from /usr/local/sbin/opensips...done.
[New LWP 4989]
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib64/libthread_db.so.1".
Core was generated by `/usr/local/sbin/opensips -P /var/run/opensips.pid -f /usr/local/etc/opensips/op'.
Program terminated with signal 11, Segmentation fault.
#0 __list_del (next=0x100100, prev=0x200200) at ../usrloc/../../lib/list.h:96
96 next->prev = prev;
Missing separate debuginfos, use: debuginfo-install cyrus-sasl-lib-2.1.26-23.el7.x86_64 glibc-2.17-222.el7.x86_64 gmp-6.0.0-15.el7.x86_64 gnutls-3.3.26-9.el7.x86_64 keyutils-libs-1.5.8-3.el7.x86_64 krb5-libs-1.15.1-37.el7_7.2.x86_64 libcom_err-1.42.9-16.el7.x86_64 libcurl-7.29.0-54.el7.x86_64 libffi-3.0.13-18.el7.x86_64 libgcc-4.8.5-39.el7.x86_64 libgcrypt-1.5.3-14.el7.x86_64 libgpg-error-1.12-3.el7.x86_64 libidn-1.28-4.el7.x86_64 libmicrohttpd-0.9.33-2.el7.x86_64 librabbitmq-0.8.0-2.el7.x86_64 libselinux-2.5-14.1.el7.x86_64 libssh2-1.4.3-10.el7_2.1.x86_64 libstdc++-4.8.5-39.el7.x86_64 libtasn1-4.10-1.el7.x86_64 libxml2-2.9.1-6.el7_2.3.x86_64 mariadb-libs-5.5.64-1.el7.x86_64 nettle-2.7.1-8.el7.x86_64 nspr-4.19.0-1.el7_5.x86_64 nss-3.36.0-5.el7_5.x86_64 nss-pem-1.0.3-7.el7.x86_64 nss-softokn-3.36.0-5.el7_5.x86_64 nss-softokn-freebl-3.36.0-5.el7_5.x86_64 nss-sysinit-3.36.0-5.el7_5.x86_64 nss-util-3.36.0-1.el7_5.x86_64 openldap-2.4.44-21.el7_6.x86_64 openssl-libs-1.0.2k-19.el7.x86_64 p11-kit-0.23.5-3.el7.x86_64 pcre-8.32-17.el7.x86_64 sqlite-3.7.17-8.el7.x86_64 xz-libs-5.2.2-1.el7.x86_64 zlib-1.2.7-18.el7.x86_64
(gdb) bt
#0 __list_del (next=0x100100, prev=0x200200) at ../usrloc/../../lib/list.h:96
#1 list_del (entry=0x7fb043da64c0) at ../usrloc/../../lib/list.h:108
#2 ping_checker_timer (ticks=, timer_idx=) at nathelper.c:1714
#3 0x00000000004b3a2f in handle_timer_job () at timer.c:731
#4 0x00000000005cb64d in handle_io (idx=, event_type=2, fm=0x7fb0458f8248) at net/net_udp.c:265
#5 io_wait_loop_epoll (h=, t=, repeat=) at net/../io_wait_loop.h:284
#6 udp_start_processes (chd_rank=chd_rank@entry=0x93d730 <chd_rank.11790>, startup_done=startup_done@entry=0x7fb043d49ae8) at net/net_udp.c:389
#7 0x000000000041b533 in main_loop () at main.c:784
#8 main (argc=, argv=) at main.c:1442
(gdb) bt full
#0 __list_del (next=0x100100, prev=0x200200) at ../usrloc/../../lib/list.h:96
No locals.
#1 list_del (entry=0x7fb043da64c0) at ../usrloc/../../lib/list.h:108
No locals.
#2 ping_checker_timer (ticks=, timer_idx=) at nathelper.c:1714
ctime = 1596479571
ct_coords =
it = 0x7fb043da64c0
itx = 0x100100
_d =
table = 0x7fb043b71068
cell = 0x7fb043da6478
FUNCTION = "ping_checker_timer"
#3 0x00000000004b3a2f in handle_timer_job () at timer.c:731
t = 0x7fb043cf10a8
l =
FUNCTION = "handle_timer_job"
#4 0x00000000005cb64d in handle_io (idx=, event_type=2, fm=0x7fb0458f8248) at net/net_udp.c:265
n = 0
read = 0
#5 io_wait_loop_epoll (h=, t=, repeat=) at net/../io_wait_loop.h:284
ep_event = {events = 0, data = {ptr = 0x4384739800000000, fd = 0, u32 = 0, u64 = 4865140594139201536}}
ret =
n = 2
r = 3
e = 0x7fb0458f8248
fd =
i =
#6 udp_start_processes (chd_rank=chd_rank@entry=0x93d730 <chd_rank.11790>, startup_done=startup_done@entry=0x7fb043d49ae8) at net/net_udp.c:389
si =
pid =
i =
FUNCTION = "udp_start_processes"
#7 0x000000000041b533 in main_loop () at main.c:784
startup_done = 0x7fb043d49ae8
chd_rank = 8
rc =
#8 main (argc=, argv=) at main.c:1442
cfg_stream =
c =
r =
tmp = 0x1 <Address 0x1 out of bounds>
---Type to continue, or q to quit---

OPENSIPS LOGS :
[timer_route][call_schedule_hangup] content type header of response IS : text/html <<<==
opensips.log-04082020:Aug 3 20:32:50 CentOS7 /usr/local/sbin/opensips[4994]: [timer_route][call_schedule_hangup] STATUS CODE OF HTTP RESPONSE : 502 <<<==
opensips.log-04082020:Aug 3 20:32:50 CentOS7 /usr/local/sbin/opensips[4994]: [timer_route][call_schedule_hangup]rest_post() rcode=502
opensips.log-04082020:Aug 3 20:32:50 CentOS7 /usr/local/sbin/opensips[4994]: WARNING:core:handle_timer_job: timer job <timer_route> has a 385218160000 us delay in execution
opensips.log-04082020:Aug 3 20:32:50 CentOS7 /usr/local/sbin/opensips[4994]: [TIMER_ROUTE] CURRENT TIME IS : 1596479570 2020-08-03 20:32:50 <<<<====
opensips.log-04082020:Aug 3 20:32:50 CentOS7 /usr/local/sbin/opensips[4981]: WARNING:core:utimer_ticker: utimer task already scheduled for 385217390 ms (now 385218190 ms), it may overlap..
opensips.log-04082020:Aug 3 20:32:50 CentOS7 /usr/local/sbin/opensips[4981]: WARNING:core:utimer_ticker: utimer task already scheduled for 385217390 ms (now 385218290 ms), it may overlap..
opensips.log-04082020:Aug 3 20:32:51 CentOS7 /usr/local/sbin/opensips[4981]: WARNING:core:utimer_ticker: utimer task already scheduled for 385217390 ms (now 385218380 ms), it may overlap..
opensips.log-04082020:Aug 3 20:32:51 CentOS7 /usr/local/sbin/opensips[4989]: [timer_route][call_schedule_hangup] HTTP BODY RESPONSE IS : #12#012#012 #12 <title>The page is temporarily unavailable</title>#12 #12 <style type="text/css">#12 //#12 </style>#12 #12#012 #12

nginx error!

#12#012
#12#012

The page you are looking for is temporarily unavailable. Please try again later.

#12#012
#12

Website Administrator

#12
#12

Something has triggered an error on your#012 website. This is the default error page for#012 nginx that is distributed with#012 Fedora. It is located#012 /usr/share/nginx/html/50x.html

#12#012

You should customize this error page for your own#012 site or edit the error_page directive in#012 the nginx configuration file#012 /etc/nginx/nginx.conf.

#12#012
#12
#12#012 #12
#12 #12 <<<==
opensips.log-04082020:Aug 3 20:32:51 CentOS7 /usr/local/sbin/opensips[4989]: [timer_route][call_schedule_hangup] content type header of response IS : text/html <<<==
opensips.log-04082020:Aug 3 20:32:51 CentOS7 /usr/local/sbin/opensips[4989]: [timer_route][call_schedule_hangup] STATUS CODE OF HTTP RESPONSE : 502 <<<==
opensips.log-04082020:Aug 3 20:32:51 CentOS7 /usr/local/sbin/opensips[4989]: [timer_route][call_schedule_hangup]rest_post() rcode=502
opensips.log-04082020:Aug 3 20:32:51 CentOS7 /usr/local/sbin/opensips[4989]: WARNING:nathelper:parse_branch: received ping response for a removed contact
opensips.log-04082020:Aug 3 20:32:51 CentOS7 /usr/local/sbin/opensips[4989]: WARNING:core:handle_timer_job: timer job has a 264420000 us delay in execution
opensips.log-04082020:Aug 3 20:32:51 CentOS7 /usr/local/sbin/opensips[4989]: WARNING:nathelper:parse_branch: received ping response for a removed contact
opensips.log-04082020:Aug 3 20:32:51 CentOS7 /usr/local/sbin/opensips[4989]: WARNING:core:handle_timer_job: timer job has a 264420000 us delay in execution
opensips.log-04082020:Aug 3 20:32:51 CentOS7 /usr/local/sbin/opensips[4989]: WARNING:core:handle_timer_job: timer job has a 264420000 us delay in execution
opensips.log-04082020:Aug 3 20:32:51 CentOS7 /usr/local/sbin/opensips[4989]: CRITICAL:core:sig_usr: segfault in process pid: 4989, id: 14
opensips.log-04082020:Aug 3 20:32:51 CentOS7 /usr/local/sbin/opensips[4976]: ERROR:mi_xmlrpc_ng:mi_xmlrpc_http_run_mi_cmd: Empty content for node [string]
opensips.log-04082020:Aug 3 20:32:51 CentOS7 /usr/local/sbin/opensips[4976]: ERROR:mi_xmlrpc_ng:mi_xmlrpc_http_answer_to_connection: no reply
opensips.log-04082020:Aug 3 20:32:51 CentOS7 /usr/local/sbin/opensips[4976]: ERROR:mi_xmlrpc_ng:mi_xmlrpc_http_run_mi_cmd: Empty content for node [string]
opensips.log-04082020:Aug 3 20:32:51 CentOS7 /usr/local/sbin/opensips[4976]: ERROR:mi_xmlrpc_ng:mi_xmlrpc_http_answer_to_connection: no reply
opensips.log-04082020:Aug 3 20:32:51 CentOS7 /usr/local/sbin/opensips[4976]: ERROR:mi_xmlrpc_ng:mi_xmlrpc_http_run_mi_cmd: Empty content for node [string]
opensips.log-04082020:Aug 3 20:32:51 CentOS7 /usr/local/sbin/opensips[4976]: ERROR:mi_xmlrpc_ng:mi_xmlrpc_http_answer_to_connection: no reply
opensips.log-04082020:Aug 3 20:32:51 CentOS7 /usr/local/sbin/opensips[4976]: ERROR:mi_xmlrpc_ng:mi_xmlrpc_http_run_mi_cmd: Empty content for node [string]
opensips.log-04082020:Aug 3 20:32:51 CentOS7 /usr/local/sbin/opensips[4976]: ERROR:mi_xmlrpc_ng:mi_xmlrpc_http_answer_to_connection: no reply
opensips.log-04082020:Aug 3 20:32:51 CentOS7 /usr/local/sbin/opensips[4976]: ERROR:mi_xmlrpc_ng:mi_xmlrpc_http_run_mi_cmd: Empty content for node [string]
opensips.log-04082020:Aug 3 20:32:51 CentOS7 /usr/local/sbin/opensips[4976]: ERROR:mi_xmlrpc_ng:mi_xmlrpc_http_answer_to_connection: no reply
opensips.log-04082020:Aug 3 20:32:51 CentOS7 /usr/local/sbin/opensips[4981]: WARNING:core:utimer_ticker: utimer task already scheduled for 385217390 ms (now 385218480 ms), it may overlap..
opensips.log-04082020:Aug 3 20:32:51 CentOS7 /usr/local/sbin/opensips[4976]: ERROR:mi_xmlrpc_ng:mi_xmlrpc_http_run_mi_cmd: Empty content for node [string]
opensips.log-04082020:Aug 3 20:32:51 CentOS7 /usr/local/sbin/opensips[4976]: ERROR:mi_xmlrpc_ng:mi_xmlrpc_http_answer_to_connection: no reply
opensips.log-04082020:Aug 3 20:32:51 CentOS7 /usr/local/sbin/opensips[4981]: WARNING:core:utimer_ticker: utimer task already scheduled for 385217390 ms (now 385218580 ms), it may overlap..
opensips.log-04082020:Aug 3 20:32:51 CentOS7 /usr/local/sbin/opensips[4999]: CRITICAL:core:handle_worker: dead child 14 (EOF received), pid 4989
opensips.log-04082020:Aug 3 20:32:51 CentOS7 /usr/local/sbin/opensips[4974]: INFO:core:handle_sigs: child process 4989 exited by a signal 11
opensips.log-04082020:Aug 3 20:32:51 CentOS7 /usr/local/sbin/opensips[4974]: INFO:core:handle_sigs: core was generated
opensips.log-04082020:Aug 3 20:32:51 CentOS7 /usr/local/sbin/opensips[4974]: INFO:core:handle_sigs: terminating due to SIGCHLD
opensips.log-04082020:Aug 3 20:32:51 CentOS7 /usr/local/sbin/opensips[4976]: INFO:core:sig_usr: signal 15 received
opensips.log-04082020:Aug 3 20:32:51 CentOS7 /usr/local/sbin/opensips[4977]: INFO:core:sig_usr: signal 15 received
opensips.log-04082020:Aug 3 20:32:51 CentOS7 /usr/local/sbin/opensips[4981]: INFO:core:sig_usr: signal 15 received
opensips.log-04082020:Aug 3 20:32:51 CentOS7 /usr/local/sbin/opensips[4978]: INFO:core:sig_usr: signal 15 received
opensips.log-04082020:Aug 3 20:32:51 CentOS7 /usr/local/sbin/opensips[4979]: INFO:core:sig_usr: signal 15 received
opensips.log-04082020:Aug 3 20:32:51 CentOS7 /usr/local/sbin/opensips[4980]: INFO:core:sig_usr: signal 15 received
opensips.log-04082020:Aug 3 20:32:51 CentOS7 /usr/local/sbin/opensips[4974]: INFO:core:shutdown_opensips: process 24(4999) [TCP main] terminated, still waiting for 22 more
opensips.log-04082020:Aug 3 20:32:51 CentOS7 /usr/local/sbin/opensips[4974]: INFO:core:shutdown_opensips: process 3(4978) [event-route handler] terminated, still waiting for 21 more
opensips.log-04082020:Aug 3 20:32:51 CentOS7 /usr/local/sbin/opensips[4974]: INFO:core:shutdown_opensips: process 4(4979) [MI FIFO] terminated, still waiting for 20 more
opensips.log-04082020:Aug 3 20:32:51 CentOS7 /usr/local/sbin/opensips[4974]: INFO:core:shutdown_opensips: process 5(4980) [time_keeper] terminated, still waiting for 19 more
opensips.log-04082020:Aug 3 20:32:51 CentOS7 /usr/local/sbin/opensips[4974]: INFO:core:shutdown_opensips: process 6(4981) [timer] terminated, still waiting for 18 more
opensips.log-04082020:Aug 3 20:32:51 CentOS7 /usr/local/sbin/opensips[4974]: INFO:core:shutdown_opensips: process 2(4977) [RabbitMQ sender] terminated, still waiting for 17 more
opensips.log-04082020:Aug 3 20:32:51 CentOS7 /usr/local/sbin/opensips[4974]: INFO:core:shutdown_opensips: process 1(4976) [HTTPD 172.16.1.5:8889] terminated, still waiting for 16 more
@bogdan-iancu
Copy link
Member

@imdrpn , are you sure the crash is related to the curl lookup ? according to the backtrace the crash happens in the nathelper pinger...could you doublecheck ?

@imdrpn
Copy link
Author

imdrpn commented Aug 9, 2020

@bogdan-iancu Yes you are right , here i am placing another core and related logs for the same which was generated before two days :

opensips log :
messages-20200809:Aug 6 19:47:54 CentOS7 /usr/local/sbin/opensips[2984]: [E_DLG_STATE_CHANGED]
messages-20200809:Aug 6 19:47:54 CentOS7 /usr/local/sbin/opensips[2984]: E_DLG_STATE_CHANGED: 683;1930833914;uL0rhoxeGE;wgBuqLIL0;00090110134050;2;3
messages-20200809:Aug 6 19:47:54 CentOS7 /usr/local/sbin/opensips[2988]: WARNING:nathelper:parse_branch: received ping response for a removed contact
messages-20200809:Aug 6 19:47:54 CentOS7 /usr/local/sbin/opensips[2988]: WARNING:nathelper:parse_branch: received ping response for a removed contact
messages-20200809:Aug 6 19:47:54 CentOS7 /usr/local/sbin/opensips[2985]: WARNING:nathelper:parse_branch: received ping response for a removed contact
messages-20200809:Aug 6 19:47:54 CentOS7 /usr/local/sbin/opensips[2985]: WARNING:rr:after_loose: no socket found to match 2nd RR [1][197.xx.1y4.14z:5060]
messages-20200809:Aug 6 19:47:54 CentOS7 /usr/local/sbin/opensips[2985]: [E_DLG_STATE_CHANGED]
messages-20200809:Aug 6 19:47:54 CentOS7 /usr/local/sbin/opensips[2985]: E_DLG_STATE_CHANGED: 683;1930833914;uL0rhoxeGE;wgBuqLIL0;00090110134050;3;4
messages-20200809:Aug 6 19:47:54 CentOS7 /usr/local/sbin/opensips[2985]: E_DLG_STATE_CHANGED: [NEW_STATE][4] [2020-08-06 19:47:54]
messages-20200809:Aug 6 19:47:54 CentOS7 /usr/local/sbin/opensips[2985]: E_DLG_STATE_CHANGED: [UPDATE tbl_active_call SET ac_answer_time='2020-08-06 19:47:54' WHERE ac_callid='uL0rhoxeGE']
messages-20200809:Aug 6 19:47:54 CentOS7 /usr/local/sbin/opensips[2985]: ERROR:dialog:dlg_validate_dialog: failed to validate remote contact: dlg=[sip:+xx789yz2893@1xx.12y.4c.1z6:5060;transport=udp] , req=[sip:0810181900@1xx.12y.4c.1z6:5060;transport=udp]
messages-20200809:Aug 6 19:47:54 CentOS7 /usr/local/sbin/opensips[2985]: [WITHINDIALOG] [uL0rhoxeGE]In-Dialog ACK from 4Y.1Z1.7X.1Y1 (callid=uL0rhoxeGE) is not valid according to dialog
messages-20200809:Aug 6 19:47:54 CentOS7 /usr/local/sbin/opensips[2996]: [TIMER_ROUTE] CURRENT TIME IS : 1596736074 2020-08-06 19:47:54 <<<<====
messages-20200809:Aug 6 19:47:54 CentOS7 /usr/local/sbin/opensips[2975]: ERROR:mi_xmlrpc_ng:mi_xmlrpc_http_run_mi_cmd: Empty content for node [string]
messages-20200809:Aug 6 19:47:54 CentOS7 /usr/local/sbin/opensips[2975]: ERROR:mi_xmlrpc_ng:mi_xmlrpc_http_answer_to_connection: no reply
messages-20200809:Aug 6 19:47:54 CentOS7 /usr/local/sbin/opensips[2975]: ERROR:mi_xmlrpc_ng:mi_xmlrpc_http_run_mi_cmd: Empty content for node [string]
messages-20200809:Aug 6 19:47:54 CentOS7 /usr/local/sbin/opensips[2975]: ERROR:mi_xmlrpc_ng:mi_xmlrpc_http_answer_to_connection: no reply
messages-20200809:Aug 6 19:47:54 CentOS7 /usr/local/sbin/opensips[2988]: CRITICAL:core:sig_usr: segfault in process pid: 2988, id: 14
messages-20200809:Aug 6 19:47:54 CentOS7 kernel: opensips[2988]: segfault at 100100 ip 00007f53f8dfddc4 sp 00007ffe085c3d90 error 6 in nathelper.so[7f53f8dfb000+1a000]
messages-20200809:Aug 6 19:47:54 CentOS7 /usr/local/sbin/opensips[2996]: [timer_route][call_schedule_hangup] HTTP BODY RESPONSE IS : <<<==
messages-20200809:Aug 6 19:47:54 CentOS7 /usr/local/sbin/opensips[2996]: [timer_route][call_schedule_hangup] content type header of response IS : text/html; charset=UTF-8 <<<==
messages-20200809:Aug 6 19:47:54 CentOS7 /usr/local/sbin/opensips[2996]: [timer_route][call_schedule_hangup] STATUS CODE OF HTTP RESPONSE : 200 <<<==
messages-20200809:Aug 6 19:47:54 CentOS7 /usr/local/sbin/opensips[2998]: CRITICAL:core:handle_worker: dead child 14 (EOF received), pid 2988
messages-20200809:Aug 6 19:47:54 CentOS7 /usr/local/sbin/opensips[2973]: INFO:core:handle_sigs: child process 2988 exited by a signal 11
messages-20200809:Aug 6 19:47:54 CentOS7 /usr/local/sbin/opensips[2973]: INFO:core:handle_sigs: core was generated
messages-20200809:Aug 6 19:47:54 CentOS7 /usr/local/sbin/opensips[2973]: INFO:core:handle_sigs: terminating due to SIGCHLD
messages-20200809:Aug 6 19:47:54 CentOS7 /usr/local/sbin/opensips[2975]: INFO:core:sig_usr: signal 15 received
messages-20200809:Aug 6 19:47:54 CentOS7 /usr/local/sbin/opensips[2980]: INFO:core:sig_usr: signal 15 received
messages-20200809:Aug 6 19:47:54 CentOS7 /usr/local/sbin/opensips[2976]: INFO:core:sig_usr: signal 15 received
messages-20200809:Aug 6 19:47:54 CentOS7 /usr/local/sbin/opensips[2979]: INFO:core:sig_usr: signal 15 received
messages-20200809:Aug 6 19:47:54 CentOS7 /usr/local/sbin/opensips[2978]: INFO:core:sig_usr: signal 15 received
messages-20200809:Aug 6 19:47:54 CentOS7 /usr/local/sbin/opensips[2977]: INFO:core:sig_usr: signal 15 received
messages-20200809:Aug 6 19:47:54 CentOS7 /usr/local/sbin/opensips[2973]: INFO:core:shutdown_opensips: process 12(2986) [SIP receiver udp:172.XX.Y.Z:5070 ] terminated, still waiting for 22 more
messages-20200809:Aug 6 19:47:54 CentOS7 /usr/local/sbin/opensips[2973]: INFO:core:shutdown_opensips: process 11(2985) [SIP receiver udp:172.XX.Y.Z:5070 ] terminated, still waiting for 21 more
messages-20200809:Aug 6 19:47:54 CentOS7 /usr/local/sbin/opensips[2973]: INFO:core:shutdown_opensips: process 19(2993) [TCP receiver] terminated, still waiting for 20 more
messages-20200809:Aug 6 19:47:54 CentOS7 /usr/local/sbin/opensips[2973]: INFO:core:shutdown_opensips: process 18(2992) [TCP receiver] terminated, still waiting for 19 more
messages-20200809:Aug 6 19:47:54 CentOS7 /usr/local/sbin/opensips[2973]: INFO:core:shutdown_opensips: process 7(2981) [SIP receiver udp:172.XX.Y.Z:5060 ] terminated, still waiting for 18 more
messages-20200809:Aug 6 19:47:54 CentOS7 /usr/local/sbin/opensips[2973]: INFO:core:shutdown_opensips: process 8(2982) [SIP receiver udp:172.XX.Y.Z:5060 ] terminated, still waiting for 17 more
messages-20200809:Aug 6 19:47:54 CentOS7 /usr/local/sbin/opensips[2973]: INFO:core:shutdown_opensips: process 9(2983) [SIP receiver udp:172.XX.Y.Z:5060 ] terminated, still waiting for 16 more
messages-20200809:Aug 6 19:47:54 CentOS7 /usr/local/sbin/opensips[2973]: INFO:core:shutdown_opensips: process 5(2979) [time_keeper] terminated, still waiting for 15 more
messages-20200809:Aug 6 19:47:54 CentOS7 /usr/local/sbin/opensips[2973]: INFO:core:shutdown_opensips: process 24(2998) [TCP main] terminated, still waiting for 14 more
messages-20200809:Aug 6 19:47:54 CentOS7 /usr/local/sbin/opensips[2973]: INFO:core:shutdown_opensips: process 21(2995) [TCP receiver] terminated, still waiting for 13 more
messages-20200809:Aug 6 19:47:54 CentOS7 /usr/local/sbin/opensips[2973]: INFO:core:shutdown_opensips: process 10(2984) [SIP receiver udp:172.XX.Y.Z:5060 ] terminated, still waiting for 12 more
messages-20200809:Aug 6 19:47:54 CentOS7 /usr/local/sbin/opensips[2973]: INFO:core:shutdown_opensips: process 4(2978) [MI FIFO] terminated, still waiting for 11 more
messages-20200809:Aug 6 19:47:54 CentOS7 /usr/local/sbin/opensips[2973]: INFO:core:shutdown_opensips: process 1(2975) [HTTPD 172.XX.Y.Z:8889] terminated, still waiting for 10 more
messages-20200809:Aug 6 19:47:54 CentOS7 /usr/local/sbin/opensips[2973]: INFO:core:shutdown_opensips: process 20(2994) [TCP receiver] terminated, still waiting for 9 more
messages-20200809:Aug 6 19:47:54 CentOS7 /usr/local/sbin/opensips[2973]: INFO:core:shutdown_opensips: process 16(2990) [TCP receiver] terminated, still waiting for 8 more
messages-20200809:Aug 6 19:47:54 CentOS7 /usr/local/sbin/opensips[2973]: INFO:core:shutdown_opensips: process 6(2980) [timer] terminated, still waiting for 7 more
messages-20200809:Aug 6 19:47:54 CentOS7 /usr/local/sbin/opensips[2973]: INFO:core:shutdown_opensips: process 2(2976) [RabbitMQ sender] terminated, still waiting for 6 more
messages-20200809:Aug 6 19:47:54 CentOS7 /usr/local/sbin/opensips[2973]: INFO:core:shutdown_opensips: process 15(2989) [TCP receiver] terminated, still waiting for 5 more
messages-20200809:Aug 6 19:47:54 CentOS7 /usr/local/sbin/opensips[2973]: INFO:core:shutdown_opensips: process 13(2987) [SIP receiver udp:172.XX.Y.Z:5070 ] terminated, still waiting for 4 more
messages-20200809:Aug 6 19:47:54 CentOS7 /usr/local/sbin/opensips[2973]: INFO:core:shutdown_opensips: process 3(2977) [event-route handler] terminated, still waiting for 3 more
messages-20200809:Aug 6 19:47:54 CentOS7 /usr/local/sbin/opensips[2973]: INFO:core:shutdown_opensips: process 23(2997) [Timer handler] terminated, still waiting for 2 more
messages-20200809:Aug 6 19:47:54 CentOS7 /usr/local/sbin/opensips[2973]: INFO:core:shutdown_opensips: process 22(2996) [TCP receiver] terminated, still waiting for 1 more

core :
[root@CentOS7 /]# gdb opensips core.2988
GNU gdb (GDB) Red Hat Enterprise Linux 7.6.1-115.el7
Copyright (C) 2013 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later http://gnu.org/licenses/gpl.html
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law. Type "show copying"
and "show warranty" for details.
This GDB was configured as "x86_64-redhat-linux-gnu".
For bug reporting instructions, please see:
http://www.gnu.org/software/gdb/bugs/...
Reading symbols from /usr/local/sbin/opensips...done.
[New LWP 2988]
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib64/libthread_db.so.1".
Core was generated by `/usr/local/sbin/opensips -P /var/run/opensips.pid -f /usr/local/etc/opensips/op'.
Program terminated with signal 11, Segmentation fault.
#0 __list_del (next=0x100100, prev=0x200200) at ../usrloc/../../lib/list.h:96
96 next->prev = prev;
Missing separate debuginfos, use: debuginfo-install cyrus-sasl-lib-2.1.26-23.el7.x86_64 glibc-2.17-222.el7.x86_64 gmp-6.0.0-15.el7.x86_64 gnutls-3.3.26-9.el7.x86_64 keyutils-libs-1.5.8-3.el7.x86_64 krb5-libs-1.15.1-37.el7_7.2.x86_64 libcom_err-1.42.9-16.el7.x86_64 libcurl-7.29.0-54.el7.x86_64 libffi-3.0.13-18.el7.x86_64 libgcc-4.8.5-39.el7.x86_64 libgcrypt-1.5.3-14.el7.x86_64 libgpg-error-1.12-3.el7.x86_64 libidn-1.28-4.el7.x86_64 libmicrohttpd-0.9.33-2.el7.x86_64 librabbitmq-0.8.0-2.el7.x86_64 libselinux-2.5-14.1.el7.x86_64 libssh2-1.4.3-10.el7_2.1.x86_64 libstdc++-4.8.5-39.el7.x86_64 libtasn1-4.10-1.el7.x86_64 libxml2-2.9.1-6.el7_2.3.x86_64 mariadb-libs-5.5.64-1.el7.x86_64 nettle-2.7.1-8.el7.x86_64 nspr-4.19.0-1.el7_5.x86_64 nss-3.36.0-5.el7_5.x86_64 nss-pem-1.0.3-7.el7.x86_64 nss-softokn-3.36.0-5.el7_5.x86_64 nss-softokn-freebl-3.36.0-5.el7_5.x86_64 nss-sysinit-3.36.0-5.el7_5.x86_64 nss-util-3.36.0-1.el7_5.x86_64 openldap-2.4.44-21.el7_6.x86_64 openssl-libs-1.0.2k-19.el7.x86_64 p11-kit-0.23.5-3.el7.x86_64 pcre-8.32-17.el7.x86_64 sqlite-3.7.17-8.el7.x86_64 xz-libs-5.2.2-1.el7.x86_64 zlib-1.2.7-18.el7.x86_64
(gdb) bt
#0 __list_del (next=0x100100, prev=0x200200) at ../usrloc/../../lib/list.h:96
#1 list_del (entry=0x7f53fe1e5418) at ../usrloc/../../lib/list.h:108
#2 ping_checker_timer (ticks=, timer_idx=) at nathelper.c:1714
#3 0x00000000004b3a2f in handle_timer_job () at timer.c:731
#4 0x00000000005cb64d in handle_io (idx=, event_type=2, fm=0x7f53ffd43248) at net/net_udp.c:265
#5 io_wait_loop_epoll (h=, t=, repeat=) at net/../io_wait_loop.h:284
#6 udp_start_processes (chd_rank=chd_rank@entry=0x93d730 <chd_rank.11790>, startup_done=startup_done@entry=0x7f53fe194510) at net/net_udp.c:389
#7 0x000000000041b533 in main_loop () at main.c:784
#8 main (argc=, argv=) at main.c:1442
(gdb) bt full
#0 __list_del (next=0x100100, prev=0x200200) at ../usrloc/../../lib/list.h:96
No locals.
#1 list_del (entry=0x7f53fe1e5418) at ../usrloc/../../lib/list.h:108
No locals.
#2 ping_checker_timer (ticks=, timer_idx=) at nathelper.c:1714
ctime = 1596736074
ct_coords =
it = 0x7f53fe1e5418
itx = 0x100100
_d =
table = 0x7f53fdfbc068
cell = 0x7f53fe1e53d0
FUNCTION = "ping_checker_timer"
#3 0x00000000004b3a2f in handle_timer_job () at timer.c:731
t = 0x7f53fe13c0a8
l =
FUNCTION = "handle_timer_job"
#4 0x00000000005cb64d in handle_io (idx=, event_type=2, fm=0x7f53ffd43248) at net/net_udp.c:265
n = 0
read = 0
#5 io_wait_loop_epoll (h=, t=, repeat=) at net/../io_wait_loop.h:284
ep_event = {events = 0, data = {ptr = 0xfdc9239800000000, fd = 0, u32 = 0, u64 = 18287186897656610816}}
ret =
n = 1
r = 3
e = 0x7f53ffd43248
fd =
i =
#6 udp_start_processes (chd_rank=chd_rank@entry=0x93d730 <chd_rank.11790>, startup_done=startup_done@entry=0x7f53fe194510) at net/net_udp.c:389
si =
pid =
i =
FUNCTION = "udp_start_processes"
#7 0x000000000041b533 in main_loop () at main.c:784
startup_done = 0x7f53fe194510
chd_rank = 8
rc =
#8 main (argc=, argv=) at main.c:1442
cfg_stream =
---Type to continue, or q to quit---

@bogdan-iancu
Copy link
Member

What is your configuration for the usrloc and nathelper modules ?

@imdrpn
Copy link
Author

imdrpn commented Aug 14, 2020

Nathelper module

loadmodule "nathelper.so"
modparam("nathelper", "natping_interval", 5)
#modparam("nathelper", "ping_nated_only", 1)
modparam("nathelper", "received_avp", "$avp(received_nh)")
modparam("nathelper", "sipping_from", "sip:pinger@19x.9Y.1ZZ.1X0")
modparam("nathelper", "sipping_bflag", "SIPPING_ENABLE")
modparam("nathelper", "sipping_bflag", "SIP_PING_FLAG")
modparam("nathelper", "remove_on_timeout_bflag", "SIPPING_RTO")
modparam("nathelper", "max_pings_lost", 1)
modparam("nathelper", "natping_tcp", 1)

USeR LOCation module

loadmodule "usrloc.so"
modparam("usrloc", "nat_bflag", "NAT")
modparam("usrloc", "db_mode", 0)

@stale
Copy link

stale bot commented Aug 29, 2020

Any updates here? No progress has been made in the last 15 days, marking as stale. Will close this issue if no further updates are made in the next 30 days.

@stale stale bot added the stale label Aug 29, 2020
@imdrpn
Copy link
Author

imdrpn commented Sep 1, 2020

@bogdan-iancu any update here ? :)

@stale stale bot removed the stale label Sep 1, 2020
@stale
Copy link

stale bot commented Sep 20, 2020

Any updates here? No progress has been made in the last 15 days, marking as stale. Will close this issue if no further updates are made in the next 30 days.

@stale stale bot added the stale label Sep 20, 2020
@stale
Copy link

stale bot commented Oct 22, 2020

Marking as closed due to lack of progress for more than 30 days. If this issue is still relevant, please re-open it with additional details.

@stale stale bot closed this as completed Oct 22, 2020
@bogdan-iancu bogdan-iancu reopened this Oct 22, 2020
@stale stale bot removed the stale label Oct 22, 2020
@stale
Copy link

stale bot commented Nov 8, 2020

Any updates here? No progress has been made in the last 15 days, marking as stale. Will close this issue if no further updates are made in the next 30 days.

@stale stale bot added the stale label Nov 8, 2020
@stale
Copy link

stale bot commented Dec 19, 2020

Marking as closed due to lack of progress for more than 30 days. If this issue is still relevant, please re-open it with additional details.

@stale stale bot closed this as completed Dec 19, 2020
@bogdan-iancu
Copy link
Member

@imdrpn , is this crash still happening with the latest 2.4 ? if so, we can re-open and continue with the investigation

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
stale
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
2 participants
@bogdan-iancu @imdrpn