Hi,
I think my last email was somehow lost in transition between the mail
servers so I am starting afresh if somebody can help. If you have
already taken pains to read through this mail, kindly skip to the bottom
of the mail. Thanks for your patience.
First let me state upfront that I am relatively very new to OpenSSL.
Also please forgive me if this is not the correct mailing list for this issue.
We have a product which uses OpenSSL to connect and transfer
application level data. There are two ways to connect, and get the application
level data from *Agent* to *Client*
1. Client (C/C++) -> Agent (C/C++)
2. Client (C/C++) -> Proxy Server (Java) -> Agent (C/C++)
*Client* and *Agent* are implemented in C, while *Proxy Server* uses Java code
(This shouldn't really matter). But might be helpful for you to know.
The issue is, connecting *Client* to *Agent* is very fast (that is relatively).
While connecting *Client* to *Proxy Server* is very slow - that is orders of
magnitudes slow.
I was trying to determine the root cause. From my analysis is appears that,
maximum time on the *Client* side is taken by SSL_Connect during connection
establishment, while the actual application level data transfer takes very
small time. Similarly, on the *Proxy Server* side (Java Code), maximum time
is taken in the first read/write whichever happens first. Further, I don't
think this is a network latency issue, as the problem is very pronounced
and all the three boxes are on the same network. Also, the *Client* code
seems to be similar, whether we connect to *Agent* (method 1 above) or
*Proxy Server* (method 2 above). So, the issue is with *Proxy Server*, IMHO.
To further locate the issue, I did some tests using ssldump command,
***************************************
This is for *Client -> Agent*
***************************************
1 1 0.0023 (0.0002) C>S Handshake
ClientHello
Version 3.1
cipher suites
TLS_DHE_RSA_WITH_AES_256_CBC_SHA
TLS_DHE_DSS_WITH_AES_256_CBC_SHA
TLS_RSA_WITH_AES_256_CBC_SHA
TLS_DHE_RSA_WITH_3DES_EDE_CBC_SHA
TLS_DHE_DSS_WITH_3DES_EDE_CBC_SHA
TLS_RSA_WITH_3DES_EDE_CBC_SHA
TLS_DHE_RSA_WITH_AES_128_CBC_SHA
TLS_DHE_DSS_WITH_AES_128_CBC_SHA
TLS_RSA_WITH_AES_128_CBC_SHA
TLS_RSA_WITH_IDEA_CBC_SHA
TLS_RSA_WITH_RC4_128_SHA
Unknown value 0xff
compression methods
NULL
1 2 0.0091 (0.0068) S>C Handshake
ServerHello
Version 3.1
session_id[0]=
cipherSuite TLS_RSA_WITH_AES_256_CBC_SHA
compressionMethod NULL
1 3 0.0091 (0.0000) S>C Handshake
Certificate
1 4 0.0091 (0.0000) S>C Handshake
CertificateRequest
certificate_types rsa_sign
certificate_types dss_sign
ServerHelloDone
1 5 0.0104 (0.0013) C>S Handshake
Certificate
1 6 0.0104 (0.0000) C>S Handshake
ClientKeyExchange
1 7 0.0104 (0.0000) C>S ChangeCipherSpec
1 8 0.0104 (0.0000) C>S Handshake
1 9 0.0159 (0.0054) S>C Handshake
TLS_RSA_WITH_RC4_128_MD51 10 0.0159 (0.0000) S>C ChangeCipherSpec
1 11 0.0159 (0.0000) S>C Handshake
1 12 0.0163 (0.0004) C>S application_data
1 13 0.0174 (0.0011) S>C application_data
1 14 0.0176 (0.0001) C>S application_data
1 15 0.0186 (0.0010) S>C application_data
1 16 0.0189 (0.0002) C>S application_data
1 17 0.0200 (0.0010) S>C application_data
1 18 0.0203 (0.0002) C>S application_data
1 0.0205 (0.0002) C>S TCP FIN
1 19 0.0207 (0.0001) S>C Alert
1 0.0209 (0.0001) S>C TCP FIN
***************************************
This is for *Client -> Proxy Server*
***************************************
1 1 0.0025 (0.0025) C>S Handshake
ClientHello
Version 3.1
cipher suites
TLS_DHE_RSA_WITH_AES_256_CBC_SHA
TLS_DHE_DSS_WITH_AES_256_CBC_SHA
TLS_RSA_WITH_AES_256_CBC_SHA
TLS_DHE_RSA_WITH_3DES_EDE_CBC_SHA
TLS_DHE_DSS_WITH_3DES_EDE_CBC_SHA
TLS_RSA_WITH_3DES_EDE_CBC_SHA
TLS_DHE_RSA_WITH_AES_128_CBC_SHA
TLS_DHE_DSS_WITH_AES_128_CBC_SHA
TLS_RSA_WITH_AES_128_CBC_SHA
TLS_RSA_WITH_IDEA_CBC_SHA
TLS_RSA_WITH_RC4_128_SHA
Unknown value 0xff
compression methods
NULL
1 2 3.2949 (3.2923) S>C Handshake
ServerHello
Version 3.1
session_id[32]=
54 76 ca 2c bd 84 37 f9 98 7a b1 57 1f 61 9a 3d
40 89 58 89 e6 14 5f 39 8b 96 62 87 8f a9 30 8f
cipherSuite TLS_DHE_RSA_WITH_AES_256_CBC_SHA
compressionMethod NULL
Certificate
ServerKeyExchange
ServerHelloDone
1 3 3.3135 (0.0186) C>S Handshake
ClientKeyExchange
DiffieHellmanClientPublicValue[96]=
9c 38 d3 b5 10 3f 4d a6 54 a9 84 02 b3 f2 25 79
e1 f0 6e 6f 56 35 44 73 13 40 4e c0 6b 2a e7 64
ff 4a a0 7a 34 82 1e d9 35 70 d1 43 f8 c5 18 c4
56 54 a6 32 33 bc 1a 35 62 fe 36 cc 33 f4 a0 15
6d 7a ea 5e a6 f5 d6 d7 21 45 16 30 08 2b bc e9
4c 25 32 64 b3 a3 b9 21 db 26 b1 6c 4c 92 34 aa
1 4 3.3135 (0.0000) C>S ChangeCipherSpec
1 5 3.3135 (0.0000) C>S Handshake
1 6 3.3241 (0.0106) S>C ChangeCipherSpec
1 7 3.3638 (0.0396) S>C Handshake
1 8 3.3638 (0.0000) S>C application_data
1 9 3.3646 (0.0007) C>S application_data
1 10 3.3646 (0.0000) C>S application_data
1 11 3.4196 (0.0549) S>C application_data
1 12 3.4196 (0.0000) S>C application_data
1 13 3.4270 (0.0073) C>S application_data
1 14 3.4271 (0.0000) C>S application_data
1 15 3.4271 (0.0000) C>S application_data
1 16 3.4646 (0.0375) S>C application_data
1 17 3.4646 (0.0000) S>C application_data
1 18 3.4649 (0.0002) C>S application_data
1 19 3.4649 (0.0000) C>S application_data
1 3.4652 (0.0003) C>S TCP FIN
1 20 3.4657 (0.0005) S>C Alert
1 3.4658 (0.0000) S>C TCP FIN
************************************************************
As you can see the big time difference between the two executions - which
actually involve the same application level data. The largest chunk of
time is spent waiting for handshake from *Proxy Server*. The response time
of *Proxy Server* in replying back with ServerHello, varies greatly
between 1.5 to 11 seconds across different runs. In the present case it is
nearly 3.3 seconds - which IMO is not acceptable.
*****************************************************
Above this was previous content.
> From: owner-openssl-us...@openssl.org On Behalf Of Dave Thompson
> does Proxy code do between accepting on the [SSL]ServerSocket
> (which is Java's way of representing the listen-ing socket) and the
> first read or write -- apparently write? One particular thing, is it
> using BufferedReader/Writer on the socket streams? Java code
> often does buffered because it is more efficient than going to OS
> each time (at least for real I/O rather than ByteArray Streams).
> In that case for output you need .flush() to actually send.
> Or you could try doing .startHandshake() explicitly as soon as
> convenient after the .accept() and see what difference that
> makes (although it may only move the problem elsewhere).
Thanks Dave for your pointer. The code is actually using
BufferedReader/Writer. Further, I actually tried adding
startHandshake() explicitly after socket accept(). However, what I
observed is that now startHandshake() gets blocked and takes up
the same amount of time as the first read/write used to take. After
this change, the actual read/write calls become very fast including
the first call. So the problem it appears is in the SSL handshake
response code from the java side.
I am pretty sure the issue is not related to OpenSSL but in the
java side. Further, since it is startHandshake() that is blocking for this
much time, it is not a problem with *our* Java Code. But just to be
sure could it have anything to do with ciphers/encryption/keys etc.
Any other pointers/help is highly appreciated.
Thanks, for reading through such a lengthy email. If anybody can kindly
provide his inputs, or even point me in the right direction, I shall be
highly grateful. Any other comments or suggestions are also highly
welcome. Thanks for your patience,
Prabhat.
_______________________________________________
openssl-users mailing list
openssl-users@openssl.org
https://mta.opensslfoundation.net/mailman/listinfo/openssl-users
