[OpenSIPS-Devel] [ opensips-Bugs-3522861 ] opensips crashes on SSL connection
SourceForge.net
noreply at sourceforge.net
Mon Jun 4 12:31:04 CEST 2012
Bugs item #3522861, was opened at 2012-05-01 14:11
Message generated for change (Comment added) made by nobody
You can respond by visiting:
https://sourceforge.net/tracker/?func=detail&atid=1086410&aid=3522861&group_id=232389
Please note that this message will contain a full copy of the comment thread,
including the initial issue submission, for this request,
not just the latest update.
Category: core
Group: 1.8.x
Status: Open
Resolution: None
Priority: 5
Private: No
Submitted By: mammal ()
Assigned to: Bogdan-Andrei Iancu (bogdan_iancu)
Summary: opensips crashes on SSL connection
Initial Comment:
I'm experiencing random crashes with 1.8.0-beta-tls. I managed to recompile with debug support and the core backtrace is following:
Core was generated by `/usr/local/sbin/opensips'.
Program terminated with signal 11, Segmentation fault.
#0 0x00007f538ccd3bd5 in sk_pop_free () from /usr/lib/libcrypto.so.0.9.8
(gdb) bt
#0 0x00007f538ccd3bd5 in sk_pop_free () from /usr/lib/libcrypto.so.0.9.8
#1 0x00007f538ccdddbe in EVP_PKEY_free () from /usr/lib/libcrypto.so.0.9.8
#2 0x00007f538cd045e5 in X509_get_pubkey_parameters ()
from /usr/lib/libcrypto.so.0.9.8
#3 0x00007f538cd05443 in X509_verify_cert () from /usr/lib/libcrypto.so.0.9.8
#4 0x00007f538cfc3d47 in ssl3_output_cert_chain () from /usr/lib/libssl.so.0.9.8
#5 0x00007f538cfb6c15 in ssl3_send_server_certificate ()
from /usr/lib/libssl.so.0.9.8
#6 0x00007f538cfba5d8 in ssl3_accept () from /usr/lib/libssl.so.0.9.8
#7 0x000000000050a0d0 in tls_accept (c=0x7f53871eedc8, poll_events=0x0)
at tls/tls_server.c:235
#8 0x000000000050cc46 in tls_fix_read_conn (c=0x7f53871eedc8)
at tls/tls_server.c:888
#9 0x0000000000488883 in tcp_read_req (con=0x7f53871eedc8,
bytes_read=0x7fff2ff6f030) at tcp_read.c:452
#10 0x0000000000489ea0 in handle_io (fm=0x7f538c4bb510, idx=-1) at tcp_read.c:817
#11 0x0000000000486e95 in io_wait_loop_epoll (h=0x78ea80, t=2, repeat=0)
at io_wait.h:728
#12 0x000000000048a581 in tcp_receive_loop (unix_sock=29) at tcp_read.c:937
#13 0x0000000000484b2e in tcp_init_children (chd_rank=0x783aa8) at tcp_main.c:1819
#14 0x000000000042dd6a in main_loop () at main.c:941
#15 0x0000000000430395 in main (argc=1, argv=0x7fff2ff6f368) at main.c:1520
last relevant lines in sipis log (debug level 6) are:
May 1 20:38:22 eu /usr/local/sbin/opensips[25375]: DBG:core:parse_uri: parsed uri:#01
2 type=1 user=<>(0)#012 passwd=<>(0)#012 host=<131.227.7.41>(12)#012 port=<33711>(5):
33711#012 params=<transport=TLS>(13)#012 headers=<>(0)
May 1 20:38:22 eu /usr/local/sbin/opensips[25375]: DBG:core:parse_uri: uri params:#0
12 transport=<transport=TLS>, val=<TLS>, proto=3
May 1 20:38:22 eu /usr/local/sbin/opensips[25375]: DBG:core:parse_uri: user-param=
<>, val=<>
May 1 20:38:22 eu /usr/local/sbin/opensips[25375]: DBG:core:parse_uri: method=<>,
val=<>
May 1 20:38:22 eu /usr/local/sbin/opensips[25375]: DBG:core:parse_uri: ttl=<>, val
=<>
May 1 20:38:22 eu /usr/local/sbin/opensips[25375]: DBG:core:parse_uri: maddr=<>, v
al=<>
May 1 20:38:22 eu /usr/local/sbin/opensips[25375]: DBG:core:parse_uri: lr=<>, val=
<>
May 1 20:38:22 eu /usr/local/sbin/opensips[25375]: DBG:core:parse_uri: r2=<>, val=
<>
May 1 20:38:23 eu /usr/local/sbin/opensips[25415]: DBG:core:probe_max_sock_buff: gets
ockopt: snd is initially 262142
May 1 20:38:23 eu /usr/local/sbin/opensips[25415]: INFO:core:probe_max_sock_buff: usi
ng snd buffer of 255 kb
May 1 20:38:23 eu /usr/local/sbin/opensips[25415]: INFO:core:init_sock_keepalive: --
TCP keepalive enabled on socket
May 1 20:38:23 eu /usr/local/sbin/opensips[25415]: DBG:core:print_ip: tcpconn_new: ne
w tcp connection to: 2.49.164.26
May 1 20:38:23 eu /usr/local/sbin/opensips[25415]: DBG:core:tcpconn_new: on port 4935
1, type 3
May 1 20:38:23 eu /usr/local/sbin/opensips[25415]: DBG:core:tls_tcpconn_init: entered
: Creating a whole new ssl connection
May 1 20:38:23 eu /usr/local/sbin/opensips[25415]: DBG:core:tls_tcpconn_init: looking
up socket based TLS server domain [85.17.87.148:7071]
May 1 20:38:23 eu /usr/local/sbin/opensips[25415]: DBG:core:tls_find_server_domain: v
irtual TLS server domain not found, Using default TLS server domain settings
May 1 20:38:23 eu /usr/local/sbin/opensips[25415]: DBG:core:tls_tcpconn_init: found s
ocket based TLS server domain [0.0.0.0:0]
May 1 20:38:23 eu /usr/local/sbin/opensips[25415]: DBG:core:tls_tcpconn_init: Setting
in ACCEPT mode (server)
May 1 20:38:23 eu /usr/local/sbin/opensips[25415]: DBG:core:tcpconn_add: hashes: 453,
272
May 1 20:38:23 eu /usr/local/sbin/opensips[25415]: DBG:core:handle_new_connect: new c
onnection: 0x7f53871eedc8 71 flags: 0002
May 1 20:38:23 eu /usr/local/sbin/opensips[25415]: DBG:core:send2child: to tcp child
0 0(25376), 0x7f53871eedc8
May 1 20:38:23 eu /usr/local/sbin/opensips[25376]: DBG:core:handle_io: received n=8 c
on=0x7f53871eedc8, fd=32
May 1 20:38:23 eu /usr/local/sbin/opensips[25376]: DBG:core:io_watch_add: io_watch_ad
d(0x78ea80, 32, 2, 0x7f53871eedc8), fd_no=1
May 1 20:38:23 eu /usr/local/sbin/opensips[25376]: DBG:core:tls_update_fd: New fd is
32
May 1 20:38:23 eu /usr/local/sbin/opensips[25415]: DBG:core:handle_tcp_child: dead tc
p child 0 (pid 25376, no 0) (shutting down?)
May 1 20:38:23 eu /usr/local/sbin/opensips[25415]: DBG:core:io_watch_del: io_watch_de
l (0x78e920, 28, -1, 0x0) fd_no=60 called
May 1 20:38:23 eu /usr/local/sbin/opensips[25415]: CRITICAL:core:receive_fd: EOF on 30
May 1 20:38:23 eu /usr/local/sbin/opensips[25415]: DBG:core:handle_ser_child: dead child 15, pid 25376 (shutting down?)
May 1 20:38:23 eu /usr/local/sbin/opensips[25361]: DBG:core:handle_sigs: status = 139
May 1 20:38:23 eu /usr/local/sbin/opensips[25415]: DBG:core:io_watch_del: io_watch_del (0x78e920, 30, -1, 0x0) fd_no=59 called
May 1 20:38:23 eu /usr/local/sbin/opensips[25361]: INFO:core:handle_sigs: child process 25376 exited by a signal 11
May 1 20:38:23 eu /usr/local/sbin/opensips[25361]: INFO:core:handle_sigs: core was generated
May 1 20:38:23 eu /usr/local/sbin/opensips[25361]: INFO:core:handle_sigs: terminating due to SIGCHLD
May 1 20:38:23 eu /usr/local/sbin/opensips[25380]: INFO:core:sig_usr: signal 15 received
May 1 20:38:23 eu /usr/local/sbin/opensips[25410]: INFO:core:sig_usr: signal 15 received
May 1 20:38:23 eu /usr/local/sbin/opensips[25401]: INFO:core:sig_usr: signal 15 received
May 1 20:38:23 eu /usr/local/sbin/opensips[25378]: INFO:core:sig_usr: signal 15 received
May 1 20:38:23 eu /usr/local/sbin/opensips[25371]: INFO:core:sig_usr: signal 15 received
May 1 20:38:23 eu /usr/local/sbin/opensips[25399]: INFO:core:sig_usr: signal 15 received
----------------------------------------------------------------------
Comment By: Nobody/Anonymous (nobody)
Date: 2012-06-04 03:31
Message:
ok... I had another crash, but it seems the whole server went down now so
it may point to hardware issue. The opensips log ends abruptly in the
middle of the log message and is followed by by huge amount of binary
zeros. I'll try to move the installation to another server and retry.
Thanks
Stan
----------------------------------------------------------------------
Comment By: Bogdan-Andrei Iancu (bogdan_iancu)
Date: 2012-05-28 08:57
Message:
Your change should not be related to the crash....when you get a new core
file, please update.
Thanks and regards,
Bogdan
----------------------------------------------------------------------
Comment By: Stan K. (mammal2)
Date: 2012-05-28 03:25
Message:
I recompiled, changed the config and waiting for the cash again....
FYI: I changed a code a bit - can it be the source of problems? I needed a
way how to store a variable into SUBSCRIBE/NOTIFY dialog. How come only
INVITE is considered a dialog anyway?
Stan
diff -crB opensips-1.7.1-tls//modules/dialog/dlg_handlers.c
opensips-1.7.1-tls-patched//modules/dialog/dlg_handlers.c
*** opensips-1.7.1-tls//modules/dialog/dlg_handlers.c Wed Nov 23 15:44:24
2011
--- opensips-1.7.1-tls-patched//modules/dialog/dlg_handlers.c Wed Jan 25
14:05:37 2012
***************
*** 837,843 ****
str s;
/* module is stricly designed for dialog calls */
! if (req->first_line.u.request.method_value!=METHOD_INVITE)
return -1;
if ( (!req->to && parse_headers(req, HDR_TO_F,0)<0) || !req->to ) {
--- 837,843 ----
str s;
/* module is stricly designed for dialog calls */
! if (req->first_line.u.request.method_value!=METHOD_INVITE &&
req->first_line.u.request.method_value!=METHOD_SUBSCRIBE)
return -1;
if ( (!req->to && parse_headers(req, HDR_TO_F,0)<0) || !req->to ) {
----------------------------------------------------------------------
Comment By: Bogdan-Andrei Iancu (bogdan_iancu)
Date: 2012-05-16 09:23
Message:
Hi,
It seems to be a memory issue, and as we force our own mem function (malloc
+ free) to ssl lib, a way to debug this is to enable memory debugging into
opensips, so we could get more information on the fault (double free, mem
overwritten, etc).
Here are the instructions for how to enable the mem debugger :
http://www.opensips.org/Resources/DocsTsMem
In cfg set, memlog=6, memdump=1 (in this order).
If you need help, let me know.
Regards,
Bogdan
----------------------------------------------------------------------
Comment By: mammal ()
Date: 2012-05-15 04:16
Message:
another crash:
#0 0x00007f675d2e3e69 in ASN1_STRING_free () from
/usr/lib/libcrypto.so.0.9.8
#1 0x00007f675d2da317 in ASN1_primitive_free ()
from /usr/lib/libcrypto.so.0.9.8
#2 0x00007f675d2da6ff in ASN1_template_free ()
from /usr/lib/libcrypto.so.0.9.8
#3 0x00007f675d2da5e6 in ?? () from /usr/lib/libcrypto.so.0.9.8
#4 0x00007f675d2da735 in ASN1_item_free () from
/usr/lib/libcrypto.so.0.9.8
#5 0x00007f675d2d4e3f in ?? () from /usr/lib/libcrypto.so.0.9.8
#6 0x00007f675d2da52a in ?? () from /usr/lib/libcrypto.so.0.9.8
#7 0x00007f675d2da735 in ASN1_item_free () from
/usr/lib/libcrypto.so.0.9.8
#8 0x00007f675d2f13d1 in ?? () from /usr/lib/libcrypto.so.0.9.8
#9 0x00007f675d2bcbf0 in sk_pop_free () from /usr/lib/libcrypto.so.0.9.8
#10 0x00007f675d2f1584 in X509_STORE_free () from
/usr/lib/libcrypto.so.0.9.8
#11 0x00007f675d5bbcca in SSL_CTX_free () from /usr/lib/libssl.so.0.9.8
#12 0x00000000005085e7 in destroy_tls () at tls/tls_init.c:675
#13 0x000000000042b73a in cleanup (show_status=1) at main.c:353
#14 0x000000000042c6f7 in handle_sigs () at main.c:549
#15 0x000000000042e0e8 in main_loop () at main.c:987
#16 0x0000000000430395 in main (argc=1, argv=0x7fff817b2eb8) at main.c:1520
----------------------------------------------------------------------
You can respond by visiting:
https://sourceforge.net/tracker/?func=detail&atid=1086410&aid=3522861&group_id=232389
More information about the Devel
mailing list