Google Groups no longer supports new Usenet posts or subscriptions. Historical content remains viewable.
Dismiss
SSLv3 handshake timeouts over slow communication
716 views
Skip to first unread message
Jayant Dusane
Jun 11, 2012, 10:40:20 AM6/11/12
to
Hi All,
I am using openssl 0.9.8s in my c++ application.
SSL handshake and all post communication works fine in LAN. But SSL handshake start failing if the network latency reaches to ~100ms.
its seems like some SSL timeouts to be configured for such delayed networks! But i am not sure about any such parameter.
Can anyone help!
i am getting following error while connecting to destination:
write to 0xa7cc8 [0xb73e8] (6 bytes => 6 (0x6))
0000 - 14 03 00 00 01 01 ......
>>> SSL 3.0 Handshake [length 0028], Finished
14 00 00 24 62 e0 da 31 90 12 70 e0 24 f9 c5 2c
46 24 22 11 40 ed ae de b1 a8 9c a6 ed bc e8 3b
2a ca ab 20 31 7a 99 63
write to 0xa7cc8 [0xb73e8] (65 bytes => 65 (0x41))
0000 - 16 03 00 00 3c 05 0c 53-bc 0e 48 da 23 3b 3f 29 ....<..S..H.#;?)
0010 - 39 9b 61 e9 75 b0 3e c0-32 78 89 08 33 bb 88 42 9.a.u.>.2x..3..B
0020 - 05 d5 c0 7d 10 d4 26 dc-60 c4 ec c7 03 f5 c4 84 ...}..&.`.......
0030 - 6f 98 52 7d 37 28 e1 2b-07 7d 31 5f 8e ea 01 e4 o.R}7(.+.}1_....
0040 - 84 .
read from 0xa7cc8 [0xad270] (5 bytes => 0 (0x0))
8396:error:1409E0E5:SSL routines:SSL3_WRITE_BYTES:ssl handshake failure:s3_pkt.c:539:
Thanks,
JD
I am using openssl 0.9.8s in my c++ application.
SSL handshake and all post communication works fine in LAN. But SSL handshake start failing if the network latency reaches to ~100ms.
its seems like some SSL timeouts to be configured for such delayed networks! But i am not sure about any such parameter.
Can anyone help!
i am getting following error while connecting to destination:
write to 0xa7cc8 [0xb73e8] (6 bytes => 6 (0x6))
0000 - 14 03 00 00 01 01 ......
>>> SSL 3.0 Handshake [length 0028], Finished
14 00 00 24 62 e0 da 31 90 12 70 e0 24 f9 c5 2c
46 24 22 11 40 ed ae de b1 a8 9c a6 ed bc e8 3b
2a ca ab 20 31 7a 99 63
write to 0xa7cc8 [0xb73e8] (65 bytes => 65 (0x41))
0000 - 16 03 00 00 3c 05 0c 53-bc 0e 48 da 23 3b 3f 29 ....<..S..H.#;?)
0010 - 39 9b 61 e9 75 b0 3e c0-32 78 89 08 33 bb 88 42 9.a.u.>.2x..3..B
0020 - 05 d5 c0 7d 10 d4 26 dc-60 c4 ec c7 03 f5 c4 84 ...}..&.`.......
0030 - 6f 98 52 7d 37 28 e1 2b-07 7d 31 5f 8e ea 01 e4 o.R}7(.+.}1_....
0040 - 84 .
read from 0xa7cc8 [0xad270] (5 bytes => 0 (0x0))
8396:error:1409E0E5:SSL routines:SSL3_WRITE_BYTES:ssl handshake failure:s3_pkt.c:539:
Thanks,
JD
Dave Thompson
Jun 11, 2012, 10:49:40 PM6/11/12
to
>From: owner-ope...@openssl.org On Behalf Of Jayant Dusane
>Sent: Monday, 11 June, 2012 10:40
>I am using openssl 0.9.8s in my c++ application.
>SSL handshake and all post communication works fine in LAN. But
>SSL handshake start failing if the network latency reaches to ~100ms.
>its seems like some SSL timeouts to be configured for such delayed
>networks! But i am not sure about any such parameter.
>Can anyone help!
OpenSSL doesn't impose any timeout; it will wait forever.
I think (but haven't tested) you can setsockopt(,SO_RCVTIMEO,)
(and in principle SNDTIMEO, but TCP only waits if the pipeline
is full which shouldn't happen for SSL/TLS handshake).
But this should cause an I/O error, not "EOF".
Or you can use nonblocking socket, and do your own management
i.e. you decide whether when to keep retrying and/or waiting
and when to give up (or warn, or ask the user, or whatever).
> write to 0xa7cc8 [0xb73e8] (6 bytes => 6 (0x6))
> 0000 - 14 03 00 00 01 01 ......
That's client CCS. This should have been preceded by most of
a full negotiation, which I assume you omitted.
> >>> SSL 3.0 Handshake [length 0028], Finished
> 14 00 00 24 62 e0 da 31 90 12 70 e0 24 f9 c5 2c
> 46 24 22 11 40 ed ae de b1 a8 9c a6 ed bc e8 3b
> 2a ca ab 20 31 7a 99 63
> write to 0xa7cc8 [0xb73e8] (65 bytes => 65 (0x41))
> 0000 - 16 03 00 00 3c 05 0c 53-bc 0e 48 da 23 3b 3f 29
....<..S..H.#;?)
> 0010 - 39 9b 61 e9 75 b0 3e c0-32 78 89 08 33 bb 88 42
9.a.u.>.2x..3..B
> 0020 - 05 d5 c0 7d 10 d4 26 dc-60 c4 ec c7 03 f5 c4 84
...}..&.`.......
> 0030 - 6f 98 52 7d 37 28 e1 2b-07 7d 31 5f 8e ea 01 e4
o.R}7(.+.}1_....
> 0040 - 84 .
> read from 0xa7cc8 [0xad270] (5 bytes => 0 (0x0))
> 8396:error:1409E0E5:SSL routines:SSL3_WRITE_BYTES:ssl handshake
failure:s3_pkt.c:539:
read count 0 should occur only for "EOF" (TCP shutdown=FIN),
not timeout (or other 'real' error). Either the server is
disconnecting (or dying on Unix), which shouldn't happen at
this stage of the protocol, or something else like a firewall
is forcing a disconnect, which also shouldn't be this late,
unless maybe your delay is really long (several minutes).
The client's second transmission batch can include client-cert
if requested as well as client-kx and CCS+Finished, but if the
server doesn't like your cert or lack of cert, it should send
an alert saying so, not just disconnect.
If this is a server you can get info from, or you can create
this with such a server (perhaps one you run yourself, even
commandline s_server), what does the server say is happening?
Can you get a trace (wireshark, tcpdump, or similar) that shows
definitely if client is receiving normal FIN or something else?
If it is, and client and server are not on same LAN, can you get
a trace at server to confirm it and not middlebox is issuing FIN?
______________________________________________________________________
OpenSSL Project http://www.openssl.org
User Support Mailing List openss...@openssl.org
Automated List Manager majo...@openssl.org
>Sent: Monday, 11 June, 2012 10:40
>I am using openssl 0.9.8s in my c++ application.
>SSL handshake and all post communication works fine in LAN. But
>SSL handshake start failing if the network latency reaches to ~100ms.
>its seems like some SSL timeouts to be configured for such delayed
>networks! But i am not sure about any such parameter.
>Can anyone help!
I think (but haven't tested) you can setsockopt(,SO_RCVTIMEO,)
(and in principle SNDTIMEO, but TCP only waits if the pipeline
is full which shouldn't happen for SSL/TLS handshake).
But this should cause an I/O error, not "EOF".
Or you can use nonblocking socket, and do your own management
i.e. you decide whether when to keep retrying and/or waiting
and when to give up (or warn, or ask the user, or whatever).
> write to 0xa7cc8 [0xb73e8] (6 bytes => 6 (0x6))
> 0000 - 14 03 00 00 01 01 ......
a full negotiation, which I assume you omitted.
> >>> SSL 3.0 Handshake [length 0028], Finished
> 14 00 00 24 62 e0 da 31 90 12 70 e0 24 f9 c5 2c
> 46 24 22 11 40 ed ae de b1 a8 9c a6 ed bc e8 3b
> 2a ca ab 20 31 7a 99 63
> write to 0xa7cc8 [0xb73e8] (65 bytes => 65 (0x41))
> 0000 - 16 03 00 00 3c 05 0c 53-bc 0e 48 da 23 3b 3f 29
....<..S..H.#;?)
> 0010 - 39 9b 61 e9 75 b0 3e c0-32 78 89 08 33 bb 88 42
9.a.u.>.2x..3..B
> 0020 - 05 d5 c0 7d 10 d4 26 dc-60 c4 ec c7 03 f5 c4 84
...}..&.`.......
> 0030 - 6f 98 52 7d 37 28 e1 2b-07 7d 31 5f 8e ea 01 e4
o.R}7(.+.}1_....
> 0040 - 84 .
> read from 0xa7cc8 [0xad270] (5 bytes => 0 (0x0))
> 8396:error:1409E0E5:SSL routines:SSL3_WRITE_BYTES:ssl handshake
failure:s3_pkt.c:539:
not timeout (or other 'real' error). Either the server is
disconnecting (or dying on Unix), which shouldn't happen at
this stage of the protocol, or something else like a firewall
is forcing a disconnect, which also shouldn't be this late,
unless maybe your delay is really long (several minutes).
The client's second transmission batch can include client-cert
if requested as well as client-kx and CCS+Finished, but if the
server doesn't like your cert or lack of cert, it should send
an alert saying so, not just disconnect.
If this is a server you can get info from, or you can create
this with such a server (perhaps one you run yourself, even
commandline s_server), what does the server say is happening?
Can you get a trace (wireshark, tcpdump, or similar) that shows
definitely if client is receiving normal FIN or something else?
If it is, and client and server are not on same LAN, can you get
a trace at server to confirm it and not middlebox is issuing FIN?
______________________________________________________________________
OpenSSL Project http://www.openssl.org
User Support Mailing List openss...@openssl.org
Automated List Manager majo...@openssl.org
Jayant Dusane
Jun 12, 2012, 3:23:53 AM6/12/12
to
SO_RCVTIMEO and SO_SNDTIMEO didnt work!
and also nothing related to certifacte, firewall, authentication. because it works with 0.6 ms latency and stopped working in ~100ms latency network.
logs are :
SSL_connect:error in SSLv2/v3 write client hello B
[512]SSL_connect:error in SSLv2/v3 write client hello B
[512]SSL_connect: 180397(usec): SSLv2/v3 write client hello B
[512]SSL_connect: 280909(usec): SSLv3 read server hello A
[512]SSL_connect: 281433(usec): SSLv3 read server certificate A
[512]SSL_connect: 281486(usec): SSLv3 read server done A
[512]SSL_connect: 282071(usec): SSLv3 write client key exchange A
[512]SSL_connect: 282195(usec): SSLv3 write change cipher spec A
[512]SSL_connect: 282282(usec): SSLv3 write finished A
[512]SSL_connect: 282337(usec): SSLv3 flush data
[512]SSL_connect: 389166(usec): SSLv3 read finished A
[68]SSL_connect: 832345(usec): before/connect initialization
SSL_connect:error in SSLv2/v3 write client hello B
[68]SSL_connect:error in SSLv2/v3 write client hello B
[68]SSL_connect: 930444(usec): SSLv2/v3 write client hello B
[68]SSL_connect: 31129(usec): SSLv3 read server hello A
[68]SSL_connect: 31774(usec): SSLv3 read server certificate A
[68]SSL_connect: 31833(usec): SSLv3 read server done A
[68]SSL_connect: 32450(usec): SSLv3 write client key exchange A
[68]SSL_connect: 32578(usec): SSLv3 write change cipher spec A
[68]SSL_connect: 32668(usec): SSLv3 write finished A
[68]SSL_connect: 32745(usec): SSLv3 flush data
[68]SSL_connect: 139048(usec): SSLv3 read finished A
[503]SSL3 alert read:warning:close notify
[503]Changing to blocking socket.
[1]Changing to nonblocking socket.
[1]SSL_accept: 40758(usec): before/accept initialization
[1]Changing to nonblocking socket.
[1]SSL_accept: 40964(usec): SSLv3 read client hello A
[1]Changing to blocking socket.
[1]SSL_accept: 41027(usec): SSLv3 write server hello A
[1]SSL_accept: 41228(usec): SSLv3 write certificate A
[1]SSL_accept: 41256(usec): SSLv3 write server done A
[1]SSL_accept: 41331(usec): SSLv3 flush data
[1]Changing to nonblocking socket.
[1]SSL_accept: 148231(usec): SSLv3 read client key exchange A
[1]SSL_accept: 148455(usec): SSLv3 read finished A
[1]Changing to blocking socket.
[1]SSL_accept: 148499(usec): SSLv3 write change cipher spec A
[1]SSL_accept: 148583(usec): SSLv3 write finished A
[1]SSL_accept: 148638(usec): SSLv3 flush data
[1]Changing to nonblocking socket.
[1]Changing to blocking socket.
[1]Changing to blocking socket.
[524]SSL3 alert read:warning:close notify
[524]Changing to blocking socket.
[1]Changing to nonblocking socket.
[1]SSL_accept: 440667(usec): before/accept initialization
[1]Changing to nonblocking socket.
[1]SSL_accept: 440833(usec): SSLv3 read client hello A
[1]Changing to blocking socket.
[1]SSL_accept: 440889(usec): SSLv3 write server hello A
[1]SSL_accept: 441069(usec): SSLv3 write certificate A
[1]SSL_accept: 441098(usec): SSLv3 write server done A
[1]SSL_accept: 441164(usec): SSLv3 flush data
[1]Changing to nonblocking socket.
[1]SSL_accept: 548183(usec): SSLv3 read client key exchange A
[1]SSL_accept: 548394(usec): SSLv3 read finished A
[1]Changing to blocking socket.
[1]SSL_accept: 548436(usec): SSLv3 write change cipher spec A
[1]SSL_accept: 548520(usec): SSLv3 write finished A
[1]SSL_accept: 548574(usec): SSLv3 flush data
[1]Changing to nonblocking socket.
[1]Changing to blocking socket.
[1]Changing to blocking socket.
/close
[1]Changing to blocking socket.
[1]XpsOSSL_SSL_Impl::OSSL_Negotiate: ret=1
[1]XpsOSSL_SSL_Impl::OSSL_Negotiate: changed to blocking socket
[1]XpsOSSL_SSL_Impl::OSSL_Negotiate: err=0
[1]XpsOSSL_SSL_Impl::OSSL_Negotiate: err=SSL_ERROR_NONE
[126]Entering XpsOSSL_SSL_Impl::OSSL_Read()
[126]Entering XpsOSSL_SSL_Impl::OSSL_Read()
[126]Bytes returned=133
[126]errCode=0
[126]Leaving XpsOSSL_SSL_Impl::OSSL_Read()
[126]Entering XpsOSSL_SSL_Impl::OSSL_Write()
[126]wto=NULL
[126]Server write m_wtimeout=30 tv.tv_sec=30
[126]Leaving XpsOSSL_SSL_Impl::OSSL_Write()
[126]Entering XpsOSSL_SSL_Impl::OSSL_Read()
[126]Entering XpsOSSL_SSL_Impl::OSSL_Read()
[126]Bytes returned=-1
[126]errCode=2
[126]XpsOSSL_SSL_Impl::OSSL_Read => SSL_ERROR_WANT_READ
[126]Leaving XpsOSSL_SSL_Impl::OSSL_Read()
[126]SSL3 alert write:warning:close notify
[126]Changing to blocking socket.--
and also nothing related to certifacte, firewall, authentication. because it works with 0.6 ms latency and stopped working in ~100ms latency network.
logs are :
SSL_connect:error in SSLv2/v3 write client hello B
[512]SSL_connect:error in SSLv2/v3 write client hello B
[512]SSL_connect: 180397(usec): SSLv2/v3 write client hello B
[512]SSL_connect: 280909(usec): SSLv3 read server hello A
[512]SSL_connect: 281433(usec): SSLv3 read server certificate A
[512]SSL_connect: 281486(usec): SSLv3 read server done A
[512]SSL_connect: 282071(usec): SSLv3 write client key exchange A
[512]SSL_connect: 282195(usec): SSLv3 write change cipher spec A
[512]SSL_connect: 282282(usec): SSLv3 write finished A
[512]SSL_connect: 282337(usec): SSLv3 flush data
[512]SSL_connect: 389166(usec): SSLv3 read finished A
[68]SSL_connect: 832345(usec): before/connect initialization
SSL_connect:error in SSLv2/v3 write client hello B
[68]SSL_connect:error in SSLv2/v3 write client hello B
[68]SSL_connect: 930444(usec): SSLv2/v3 write client hello B
[68]SSL_connect: 31129(usec): SSLv3 read server hello A
[68]SSL_connect: 31774(usec): SSLv3 read server certificate A
[68]SSL_connect: 31833(usec): SSLv3 read server done A
[68]SSL_connect: 32450(usec): SSLv3 write client key exchange A
[68]SSL_connect: 32578(usec): SSLv3 write change cipher spec A
[68]SSL_connect: 32668(usec): SSLv3 write finished A
[68]SSL_connect: 32745(usec): SSLv3 flush data
[68]SSL_connect: 139048(usec): SSLv3 read finished A
[503]SSL3 alert read:warning:close notify
[503]Changing to blocking socket.
[1]Changing to nonblocking socket.
[1]SSL_accept: 40758(usec): before/accept initialization
[1]Changing to nonblocking socket.
[1]SSL_accept: 40964(usec): SSLv3 read client hello A
[1]Changing to blocking socket.
[1]SSL_accept: 41027(usec): SSLv3 write server hello A
[1]SSL_accept: 41228(usec): SSLv3 write certificate A
[1]SSL_accept: 41256(usec): SSLv3 write server done A
[1]SSL_accept: 41331(usec): SSLv3 flush data
[1]Changing to nonblocking socket.
[1]SSL_accept: 148231(usec): SSLv3 read client key exchange A
[1]SSL_accept: 148455(usec): SSLv3 read finished A
[1]Changing to blocking socket.
[1]SSL_accept: 148499(usec): SSLv3 write change cipher spec A
[1]SSL_accept: 148583(usec): SSLv3 write finished A
[1]SSL_accept: 148638(usec): SSLv3 flush data
[1]Changing to nonblocking socket.
[1]Changing to blocking socket.
[1]Changing to blocking socket.
[524]SSL3 alert read:warning:close notify
[524]Changing to blocking socket.
[1]Changing to nonblocking socket.
[1]SSL_accept: 440667(usec): before/accept initialization
[1]Changing to nonblocking socket.
[1]SSL_accept: 440833(usec): SSLv3 read client hello A
[1]Changing to blocking socket.
[1]SSL_accept: 440889(usec): SSLv3 write server hello A
[1]SSL_accept: 441069(usec): SSLv3 write certificate A
[1]SSL_accept: 441098(usec): SSLv3 write server done A
[1]SSL_accept: 441164(usec): SSLv3 flush data
[1]Changing to nonblocking socket.
[1]SSL_accept: 548183(usec): SSLv3 read client key exchange A
[1]SSL_accept: 548394(usec): SSLv3 read finished A
[1]Changing to blocking socket.
[1]SSL_accept: 548436(usec): SSLv3 write change cipher spec A
[1]SSL_accept: 548520(usec): SSLv3 write finished A
[1]SSL_accept: 548574(usec): SSLv3 flush data
[1]Changing to nonblocking socket.
[1]Changing to blocking socket.
[1]Changing to blocking socket.
/close
[1]Changing to blocking socket.
[1]XpsOSSL_SSL_Impl::OSSL_Negotiate: ret=1
[1]XpsOSSL_SSL_Impl::OSSL_Negotiate: changed to blocking socket
[1]XpsOSSL_SSL_Impl::OSSL_Negotiate: err=0
[1]XpsOSSL_SSL_Impl::OSSL_Negotiate: err=SSL_ERROR_NONE
[126]Entering XpsOSSL_SSL_Impl::OSSL_Read()
[126]Entering XpsOSSL_SSL_Impl::OSSL_Read()
[126]Bytes returned=133
[126]errCode=0
[126]Leaving XpsOSSL_SSL_Impl::OSSL_Read()
[126]Entering XpsOSSL_SSL_Impl::OSSL_Write()
[126]wto=NULL
[126]Server write m_wtimeout=30 tv.tv_sec=30
[126]Leaving XpsOSSL_SSL_Impl::OSSL_Write()
[126]Entering XpsOSSL_SSL_Impl::OSSL_Read()
[126]Entering XpsOSSL_SSL_Impl::OSSL_Read()
[126]Bytes returned=-1
[126]errCode=2
[126]XpsOSSL_SSL_Impl::OSSL_Read => SSL_ERROR_WANT_READ
[126]Leaving XpsOSSL_SSL_Impl::OSSL_Read()
[126]SSL3 alert write:warning:close notify
[126]Changing to blocking socket.
" पेपर वाचवा...झाडे वाचवा..
खुप गरज असेल तरच प्रिंट द्या.. "
Dave Thompson
Jun 14, 2012, 9:46:43 PM6/14/12
to
>From: owner-ope...@openssl.org On Behalf Of Jayant Dusane
>Sent: Tuesday, 12 June, 2012 03:24
>SO_RCVTIMEO and SO_SNDTIMEO didnt work!
>and also nothing related to certifacte, firewall, authentication.
>because it works with 0.6 ms latency and stopped working in ~100ms latency
network.
>logs are :
These logs do apparently show ~100ms latency,
but don't indicate any problem in SSL handshake.
Whatever your problem is, that's not it.
FWIW, I connected (1.0.0e) s_client and s_server
through a device that delayed every transmission
5 secs (5000 ms) and it worked fine (but slow).
0 new messages