[OpenSIPS-Users] TLS Handshake fail issue
Devang Dhandhalya
devang.dhandhalya at ecosmob.com
Tue Nov 9 11:05:34 EST 2021
Hi All
I Am Trying to Implement opensips with TLS support in a local machine . I
generate TLS server (rootCA) and TLS Client (user) certificates using
opensips-cli .
softphone : Blink version : 5.1.7
opensips version : 3.2.2
Registration with tls is working fine for TLS , at the time of calling
getting below error . I check in logs at DBG level
>From User A to opensips server tls handshake is working fine but from
opensips to User B tls handshake is going to fail please suggest how to
resolve this .
INFO level Logs :
ERROR:core:tcp_async_connect: poll error: flags 1c
ERROR:core:tcp_async_connect: failed to retrieve SO_ERROR [server=
1.2.3.4:40945] (111) Connection refused
ERROR:proto_tls:proto_tls_send: async TCP connect failed
ERROR:tm:msg_send: send() to 1.2.3.4:40945 for proto tls/3 failed
ERROR:tm:t_forward_nonack: sending request failed
ERROR:tls_openssl:openssl_tls_async_connect: New TLS connection to
1.2.3.4:34463 failed
ERROR:tls_openssl:openssl_tls_async_connect: TLS error: 1 (ret=-1)
err=Success(0)
ERROR:tls_openssl:tls_print_errstack: TLS errstack: error:14094410:SSL
routines:ssl3_read_bytes:sslv3 alert handshake failure
ERROR:proto_tls:tls_read_req: failed to do pre-tls handshake!
DBG level Logs :
DBG:core:parse_msg: SIP Request:
DBG:core:parse_msg: method: <INVITE>
DBG:core:parse_msg: uri: <sip:14682973 at 1.2.3.4:34463;transport=tls>
DBG:core:parse_msg: version: <SIP/2.0>
DBG:core:parse_headers: flags=ffffffffffffffff
DBG:core:parse_via_param: found param type 232, <branch> =
<z9hG4bK14b8.6a972877.0>; state=6
DBG:core:parse_via_param: found param type 236, <i> = <d7b6e394>; state=16
DBG:core:parse_via: end of header reached, state=5
DBG:core:parse_headers: via found, flags=ffffffffffffffff
DBG:core:parse_headers: this is the first via
DBG:core:parse_via_param: found param type 234, <received> = <1.2.3.4>;
state=6
DBG:core:parse_via_param: found param type 235, <rport> = <38119>; state=6
DBG:core:parse_via_param: found param type 232, <branch> =
<z9hG4bKPja1ee2137-d7f4-4744-89e1-ff53b4b0b06b>; state=6
DBG:core:parse_via_param: found param type 237, <alias> = <n/a>; state=16
DBG:core:parse_via: end of header reached, state=5
DBG:core:parse_headers: via found, flags=ffffffffffffffff
DBG:core:parse_headers: parse_headers: this is the second via
DBG:core:_parse_to: end of header reached, state=10
DBG:core:_parse_to: display={}, ruri={sip:1001 at 1.2.3.4}
DBG:core:get_hdr_field: <To> [26]; uri=[sip:1001 at 1.2.3.4]
DBG:core:get_hdr_field: to body [<sip:1001 at 1.2.3.4>#015#012]
DBG:core:get_hdr_field: cseq <CSeq>: <14318> <INVITE>
DBG:core:get_hdr_field: content_length=717
DBG:core:get_hdr_field: found end of header
DBG:core:parse_headers: flags=ffffffffffffffff
DBG:proto_tls:proto_tls_send: no open tcp connection found, opening new
one, async = 1
DBG:core:probe_max_sock_buff: getsockopt: snd is initially 16384
DBG:core:probe_max_sock_buff: using snd buffer of 416 kb
DBG:core:init_sock_keepalive: TCP keepalive enabled on socket 141
DBG:core:print_ip: tcpconn_new: new tcp connection to: 1.2.3.4
DBG:core:tcpconn_new: on port 34463, proto 3
DBG:tls_mgm:tls_find_client_domain: found TLS client domain: dom2
DBG:tls_openssl:openssl_tls_conn_init: Creating a whole new ssl connection
DBG:tls_openssl:openssl_tls_conn_init: Setting in CONNECT mode (client)
DBG:proto_tls:proto_tls_send: Successfully connected from interface
1.2.3.4:34463 to 1.2.3.4:36463!
DBG:proto_tls:proto_tls_send: First TCP connect attempt succeeded in less
than 100ms, proceed to TLS connect
DBG:tls_openssl:openssl_tls_update_fd: New fd is 141
DBG:core:handle_worker: read response= 7f83eb6b5118, 2, fd 119 from 8
(17254)
DBG:core:tcpconn_add: hashes: 607, 894
DBG:core:io_watch_add: [TCP_main] io_watch_add op (119 on 5)
(0x55fd3f789ae0, 119, 19, 0x7f83eb6b5118,1), fd_no=27/1024
DBG:core:handle_tcpconn_ev: data available on 0x7f83eb6b5118 119
DBG:core:io_watch_del: [TCP_main] io_watch_del op on index 2 119
(0x55fd3f789ae0, 119, 2, 0x0,0x1) fd_no=28 called
DBG:core:send2worker: to tcp worker 1 (0), 0x7f83eb6b5118 rw 1
DBG:core:handle_io: We have received conn 0x7f83eb6b5118 with rw 1 on fd 5
DBG:core:io_watch_add: [TCP_worker] io_watch_add op (5 on 102)
(0x55fd3f789ae0, 5, 19, 0x7f83eb6b5118,1), fd_no=4/1024
DBG:proto_tls:tls_read_req: Using the global ( per process ) buff
DBG:tls_openssl:openssl_tls_async_connect: handshake timeout for connection
0x7f83eb6b5118 10ms elapsed
DBG:tls_openssl:openssl_tls_update_fd: New fd is 5
ERROR:tls_openssl:openssl_tls_async_connect: New TLS connection to
1.2.3.4:34463 failed
ERROR:tls_openssl:openssl_tls_async_connect: TLS error: 1 (ret=-1)
err=Success(0)
ERROR:tls_openssl:tls_print_errstack: TLS errstack: error:14094410:SSL
routines:ssl3_read_bytes:sslv3 alert handshake failure
ERROR:proto_tls:tls_read_req: failed to do pre-tls handshake!
DBG:proto_tls:proto_tls_send: Successfully started async SSL connection
DBG:core:io_watch_del: [TCP_worker] io_watch_del op on index 0 5
(0x55fd3f789ae0, 5, 0, 0x10,0x3) fd_no=5 called
DBG:core:tcpconn_release: releasing con 0x7f83eb6b5118, state -2, fd=5,
id=1228827518
DBG:core:tcpconn_release: extra_data 0x7f83eb6bdd50
DBG:tm:insert_timer_unsafe: [0]: 0x7f83eb6a9320 (12)
DBG:core:tcpconn_release: releasing con 0x7f83eb6b5118, state -3, fd=-1,
id=1228827518
DBG:tm:t_relay_to: new transaction fwd'ed
DBG:core:tcpconn_release: extra_data 0x7f83eb6bdd50
DBG:tm:do_t_cleanup: transaction 0x7f83eb6a90d0 already updated! Skipping
update!
DBG:tm:t_unref: UNREF_UNSAFE: [0x7f83eb6a90d0] after is 0
DBG:core:destroy_avp_list: destroying list (nil)
DBG:core:receive_msg: cleaning up
DBG:proto_tls:tls_read_req: tls_read_req end
DBG:core:handle_tcp_worker: response= 7f83eb6b5118, -3 from tcp worker 0 (1)
DBG:core:tcpconn_destroy: delaying (0x7f83eb6b5118, flags 0038) ref = 1 ...
DBG:core:handle_tcp_worker: response= 7f83eb6b5118, -2 from tcp worker 0 (0)
DBG:core:tcpconn_destroy: destroying connection 0x7f83eb6b5118, flags 0038
DBG:tls_openssl:openssl_tls_update_fd: New fd is 119
DBG:tm:utimer_routine: timer routine:4,tl=0x7f83eb6a5d18 next=(nil),
timeout=7700000
DBG:tm:retransmission_handler: retransmission_handler : request resending
(t=0x7f83eb6a5af8, PUBLISH s ... )
root at devang-MS-7817:/usr/local/etc/opensips/range#
I am following this OpenSIPS TLS config:
socket=udp:1.2.3.4: <http://192.168.0.105:506/>5060
socket=tcp:1.2.3.4: <http://192.168.0.105:506/>5060
socket=tls:1.2.3.4: <http://192.168.0.105:506>5061
loadmodule "tls_openssl.so"
loadmodule "tls_mgm.so"
# -------- TLS SERVER Certificate ---------#
modparam("tls_mgm", "server_domain", "dom1")
modparam("tls_mgm", "match_sip_domain", "[dom1]devang.com")
modparam("tls_mgm", "match_ip_address", "[dom1]1.2.3.4:5061")
modparam("tls_mgm", "verify_cert", "[dom1]0")
modparam("tls_mgm", "require_cert", "[dom1]0")
modparam("tls_mgm", "tls_method", "[dom1]-")
modparam("tls_mgm", "certificate",
"[dom1]/usr/local/etc/opensips/tls/rootCA/ca_cert.pem")
modparam("tls_mgm", "private_key",
"[dom1]/usr/local/etc/opensips/tls/rootCA/private_key.pem")
# --------- TLS CLIENT CERTIFICATE --------#
modparam("tls_mgm", "client_domain", "dom2")
modparam("tls_mgm", "match_sip_domain", "[dom2]*")
modparam("tls_mgm", "match_ip_address", "[dom2]*")
modparam("tls_mgm", "verify_cert", "[dom2]0")
modparam("tls_mgm", "require_cert", "[dom2]0")
modparam("tls_mgm", "tls_method", "[dom2]-")
modparam("tls_mgm", "certificate",
"[dom2]/usr/local/etc/opensips/tls/user/user-cert.pem")
modparam("tls_mgm", "private_key",
"[dom2]/usr/local/etc/opensips/tls/user/user-privkey.pem")
modparam("tls_mgm", "ca_list",
"[dom2]/usr/local/etc/opensips/tls/user/user-calist.pem")
loadmodule "proto_tls.so"
checking the connection with s_client shows below :
openssl s_client -showcerts -debug -connect 1.2.3.4:5061 -bugs
CONNECTED(00000005)
140510082113984:error:14094458:SSL routines:ssl3_read_bytes:tlsv1
unrecognized name:../ssl/record/rec_layer_s3.c:1528:SSL alert number 112
no peer certificate available
---
No client certificate CA names sent
---
SSL handshake has read 7 bytes and written 517 bytes
Verification: OK
---
New, (NONE), Cipher is (NONE)
Secure Renegotiation IS NOT supported
Compression: NONE
Expansion: NONE
No ALPN negotiated
Early data was not sent
Verify return code: 0 (ok)
Can anyone tell me what I might be missing for tls config or Please advise
how to resolve this SSL handshake failure.
Many Thanks
Devang
70,1 15%
--
*Disclaimer*
In addition to generic Disclaimer which you have agreed on our
website, any views or opinions presented in this email are solely those of
the originator and do not necessarily represent those of the Company or its
sister concerns. Any liability (in negligence, contract or otherwise)
arising from any third party taking any action, or refraining from taking
any action on the basis of any of the information contained in this email
is hereby excluded.
*Confidentiality*
This communication (including any
attachment/s) is intended only for the use of the addressee(s) and contains
information that is PRIVILEGED AND CONFIDENTIAL. Unauthorized reading,
dissemination, distribution, or copying of this communication is
prohibited. Please inform originator if you have received it in error.
*Caution for viruses, malware etc.*
This communication, including any
attachments, may not be free of viruses, trojans, similar or new
contaminants/malware, interceptions or interference, and may not be
compatible with your systems. You shall carry out virus/malware scanning on
your own before opening any attachment to this e-mail. The sender of this
e-mail and Company including its sister concerns shall not be liable for
any damage that may incur to you as a result of viruses, incompleteness of
this message, a delay in receipt of this message or any other computer
problems.
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.opensips.org/pipermail/users/attachments/20211109/02e7acc1/attachment-0001.html>
More information about the Users
mailing list