[OpenSIPS-Users] TLS handshake failing

Răzvan Crainea razvan at opensips.org
Thu Jan 22 09:28:22 CET 2015 

Hi, Diego!

According to your logs, OpenSIPS was unable to receive any data because 
the client close the connection before sending any data. You should try 
to investigate this on the client's side.

Best regards,

Răzvan Crainea
OpenSIPS Solutions
www.opensips-solutions.com

On 01/21/2015 06:07 PM, Diego Carvalho Domingos wrote:
>
> Hi all, I’m trying to set up opensips with TLS enabled. I followed the 
> webnair to install opensips and the advanced tutorial about TLS. 
> Everything seems to be configured correctly but when I try to register 
> using TLS it fails. I tried both latest LTS version and the master 
> version of opensips, Bria and Linphone softphones and the default and 
> customized TLS certificates. For all tests I got this log:
>
> Jan 20 15:41:27 devmachine /usr/local/opensips/sbin/opensips[3318]: 
> DBG:core:probe_max_sock_buff: getsockopt: snd is initially 262142
>
> Jan 20 15:41:27 devmachine /usr/local/opensips/sbin/opensips[3318]: 
> INFO:core:probe_max_sock_buff: using snd buffer of 255 kb
>
> Jan 20 15:41:27 devmachine /usr/local/opensips/sbin/opensips[3318]: 
> INFO:core:init_sock_keepalive: -- TCP keepalive enabled on socket
>
> Jan 20 15:41:27 devmachine /usr/local/opensips/sbin/opensips[3318]: 
> DBG:core:print_ip: tcpconn_new: new tcp connection to: 192.168.14.26
>
> Jan 20 15:41:27 devmachine /usr/local/opensips/sbin/opensips[3318]: 
> DBG:core:tcpconn_new: on port 50853, type 3
>
> Jan 20 15:41:27 devmachine /usr/local/opensips/sbin/opensips[3318]: 
> DBG:core:tls_tcpconn_init: entered: Creating a whole new ssl connection
>
> Jan 20 15:41:27 devmachine /usr/local/opensips/sbin/opensips[3318]: 
> DBG:core:tls_tcpconn_init: looking up socket based TLS server domain 
> [192.168.14.23:5061]
>
> Jan 20 15:41:27 devmachine /usr/local/opensips/sbin/opensips[3318]: 
> DBG:core:tls_find_server_domain: virtual TLS server domain not found, 
> Using default TLS server domain settings
>
> Jan 20 15:41:27 devmachine /usr/local/opensips/sbin/opensips[3318]: 
> DBG:core:tls_tcpconn_init: found socket based TLS server domain 
> [0.0.0.0:0]
>
> Jan 20 15:41:27 devmachine /usr/local/opensips/sbin/opensips[3318]: 
> DBG:core:tls_tcpconn_init: Setting in ACCEPT mode (server)
>
> Jan 20 15:41:27 devmachine /usr/local/opensips/sbin/opensips[3318]: 
> DBG:core:tcpconn_add: hashes: 613, 3
>
> Jan 20 15:41:27 devmachine /usr/local/opensips/sbin/opensips[3318]: 
> DBG:core:handle_new_connect: new connection: 0x7f3aeafa9eb8 25 flags: 0002
>
> Jan 20 15:41:27 devmachine /usr/local/opensips/sbin/opensips[3318]: 
> DBG:core:send2child: to tcp child 0 0(3314), 0x7f3aeafa9eb8 rw 1
>
> Jan 20 15:41:27 devmachine /usr/local/opensips/sbin/opensips[3314]: 
> DBG:core:handle_io: We have received conn 0x7f3aeafa9eb8 with rw 1
>
> Jan 20 15:41:27 devmachine /usr/local/opensips/sbin/opensips[3314]: 
> DBG:core:io_watch_add: io_watch_add op on 20 (0x84d120, 20, 2, 
> 0x7f3aeafa9eb8,1), fd_no=1
>
> Jan 20 15:41:27 devmachine /usr/local/opensips/sbin/opensips[3314]: 
> DBG:core:tcp_read_req: Using the global ( per process ) buff
>
> Jan 20 15:41:27 devmachine /usr/local/opensips/sbin/opensips[3314]: 
> DBG:core:tls_update_fd: New fd is 20
>
> Jan 20 15:41:27 devmachine /usr/local/opensips/sbin/opensips[3314]: 
> DBG:core:tcp_read_req: Using the global ( per process ) buff
>
> Jan 20 15:41:27 devmachine /usr/local/opensips/sbin/opensips[3314]: 
> DBG:core:tls_update_fd: New fd is 20
>
> Jan 20 15:41:27 devmachine /usr/local/opensips/sbin/opensips[3314]: 
> INFO:core:tls_accept: New TLS connection from 192.168.14.26:50853 accepted
>
> Jan 20 15:41:27 devmachine /usr/local/opensips/sbin/opensips[3314]: 
> DBG:core:tls_accept: new TLS connection from 192.168.14.26:50853 using 
> TLSv1/SSLv3 AES256-SHA 256
>
> Jan 20 15:41:27 devmachine /usr/local/opensips/sbin/opensips[3314]: 
> DBG:core:tls_accept: local socket: 192.168.14.23:5061
>
> Jan 20 15:41:27 devmachine /usr/local/opensips/sbin/opensips[3314]: 
> INFO:core:tls_accept: Client did not present a TLS certificate
>
> Jan 20 15:41:27 devmachine /usr/local/opensips/sbin/opensips[3314]: 
> INFO:core:tls_dump_cert_info: tls_accept: local TLS server certificate 
> subject: /C=XY/ST=Some State/O=My Large Organization Name/OU=My 
> Subunit of Large 
> Organization/CN=somename.somewhere.com/emailAddress=root at somename.somewhere.com, 
> issuer: 
> /CN=Your_NAME/ST=Your_STATE/C=CO/emailAddress=YOUR_EMAIL/O=YOUR_ORG_NAME
>
> Jan 20 15:41:27 devmachine /usr/local/opensips/sbin/opensips[3314]: 
> DBG:core:tls_update_fd: New fd is 20
>
> Jan 20 15:41:27 devmachine /usr/local/opensips/sbin/opensips[3314]: 
> DBG:core:tcp_read_req: read= 0 bytes, parsed=0, state=0, error=1
>
> Jan 20 15:41:27 devmachine /usr/local/opensips/sbin/opensips[3314]: 
> DBG:core:tcp_read_req: last char=0x00, parsed msg=#012
>
> Jan 20 15:41:27 devmachine /usr/local/opensips/sbin/opensips[3314]: 
> DBG:core:tcp_read_req: We didn't manage to read a full request. Back 
> to child poll
>
> Jan 20 15:41:27 devmachine /usr/local/opensips/sbin/opensips[3314]: 
> DBG:core:tcp_read_req: tcp_read_req end
>
> Jan 20 15:41:27 devmachine /usr/local/opensips/sbin/opensips[3314]: 
> DBG:core:tcp_read_req: Using the per connection buff
>
> Jan 20 15:41:27 devmachine /usr/local/opensips/sbin/opensips[3314]: 
> DBG:core:tls_update_fd: New fd is 20
>
> Jan 20 15:41:27 devmachine /usr/local/opensips/sbin/opensips[3314]: 
> INFO:core:_tls_read: TLS connection to 192.168.14.26:50853 closed cleanly
>
> Jan 20 15:41:27 devmachine /usr/local/opensips/sbin/opensips[3314]: 
> DBG:core:tcp_read_req: read= 0 bytes, parsed=0, state=0, error=1
>
> Jan 20 15:41:27 devmachine /usr/local/opensips/sbin/opensips[3314]: 
> DBG:core:tcp_read_req: last char=0x00, parsed msg=#012
>
> Jan 20 15:41:27 devmachine /usr/local/opensips/sbin/opensips[3314]: 
> DBG:core:tcp_read_req: EOF
>
> Jan 20 15:41:27 devmachine /usr/local/opensips/sbin/opensips[3314]: 
> DBG:core:io_watch_del: io_watch_del op on index -1 20 (0x84d120, 20, 
> -1, 0x10,0x3) fd_no=2 called
>
> Jan 20 15:41:27 devmachine /usr/local/opensips/sbin/opensips[3314]: 
> DBG:core:release_tcpconn:  releasing con 0x7f3aeafa9eb8, state -1, 
> fd=20, id=3
>
> Jan 20 15:41:27 devmachine /usr/local/opensips/sbin/opensips[3314]: 
> DBG:core:release_tcpconn:  extra_data 0x7f3aeafaa038
>
> Jan 20 15:41:27 devmachine /usr/local/opensips/sbin/opensips[3318]: 
> DBG:core:handle_tcp_child: reader response= 7f3aeafa9eb8, -1 from 0
>
> Jan 20 15:41:27 devmachine /usr/local/opensips/sbin/opensips[3318]: 
> DBG:core:tcpconn_destroy: destroying connection 0x7f3aeafa9eb8, flags 0002
>
> Jan 20 15:41:27 devmachine /usr/local/opensips/sbin/opensips[3318]: 
> DBG:core:tls_close: closing TLS connection
>
> Jan 20 15:41:27 devmachine /usr/local/opensips/sbin/opensips[3318]: 
> DBG:core:tls_update_fd: New fd is 25
>
> Jan 20 15:41:27 devmachine /usr/local/opensips/sbin/opensips[3318]: 
> DBG:core:tls_shutdown: shutdown successful
>
> Jan 20 15:41:27 devmachine /usr/local/opensips/sbin/opensips[3318]: 
> DBG:core:tls_tcpconn_clean: entered
>
> So it seems the TLS connection was accepted:
>
> Jan 20 15:41:27 devmachine /usr/local/opensips/sbin/opensips[3314]: 
> INFO:core:tls_accept: New TLS connection from 192.168.14.26:50853 accepted
>
> Jan 20 15:41:27 devmachine /usr/local/opensips/sbin/opensips[3314]: 
> DBG:core:tls_accept: new TLS connection from 192.168.14.26:50853 using 
> TLSv1/SSLv3 AES256-SHA 256
>
> But then some error occurs and the connection is closed:
>
> Jan 20 15:41:27 devmachine /usr/local/opensips/sbin/opensips[3314]: 
> DBG:core:tcp_read_req: We didn't manage to read a full request. Back 
> to child poll
>
> Jan 20 15:41:27 devmachine /usr/local/opensips/sbin/opensips[3314]: 
> DBG:core:tcp_read_req: tcp_read_req end
>
> Jan 20 15:41:27 devmachine /usr/local/opensips/sbin/opensips[3314]: 
> DBG:core:tcp_read_req: Using the per connection buff
>
> Jan 20 15:41:27 devmachine /usr/local/opensips/sbin/opensips[3314]: 
> DBG:core:tls_update_fd: New fd is 20
>
> Jan 20 15:41:27 devmachine /usr/local/opensips/sbin/opensips[3314]: 
> INFO:core:_tls_read: TLS connection to 192.168.14.26:50853 closed cleanly
>
> Any help is appreciated. Thanks.
>
>
>
> _______________________________________________
> Users mailing list
> Users at lists.opensips.org
> http://lists.opensips.org/cgi-bin/mailman/listinfo/users

-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.opensips.org/pipermail/users/attachments/20150122/500eab39/attachment-0001.htm>

More information about the Users mailing list