SSL Handshake_failure in Java test client while connecting to server with two-way authentication

Question

I've been stuck for a couple of days now, and I've checked several answers already ( this, this, this, this, this, this, this, this ), but I haven't been able to solve my problem. I'm new to SSL, and there does not appear to be anyone else in my organization who has done this.

Background

We currently have a set of terminals in retailer outlets connecting to a server via SSL. The connection includes client authentication. My organization is acting as a CA and has issued a cacert.crt certificate and used it to sign a certificate for the server and one certificate for all of the client terminals. The terminals currently work correctly with the server, but I'm unable to get detailed information about the current connection or configuration from the people who support the environment... It appears that the system was purchased years ago from a combination of vendors, and the knowledge has been lost. I'm currently trying to develop a separate client that can communicate with the server outside of the existing terminals.

Problem

I've developed a very simple Java SSL client in order to better understand the SSL configuration and learn where and how the certificates and keys need to be referenced in order to connect. Unfortunately, I've been unable to connect successfully to the server, and I'm not sure what is wrong or what else to check.

I've been able to produce a debug log of the SSL connection (attached below). I've also been able to produce a log from running openssl's s_client function, but I'm not familiar with the tool and so I'm not sure what it's telling me. I've attached all of the code and logs, and I'm hoping you can provide me with some insight on what the problem is.

Since I'm new to SSL, I'm not sure if I've provided all of the pertinent information. Please let me know if you need any further information.

Simple Java Client

public class Client {
    private static String serverIP  = "{snip: server IP}";
    private static int serverPort   = {snip: port number};


    public static void main(String[] arstring) {
        try {
            SSLSocketFactory sslsocketfactory = (SSLSocketFactory) SSLSocketFactory.getDefault();
            SSLSocket sslsocket = (SSLSocket) sslsocketfactory.createSocket(Client.serverIP, Client.serverPort);

            InputStream inputstream = System.in;
            InputStreamReader inputstreamreader = new InputStreamReader(inputstream);
            BufferedReader bufferedreader = new BufferedReader(inputstreamreader);

            OutputStream outputstream = sslsocket.getOutputStream();
            OutputStreamWriter outputstreamwriter = new OutputStreamWriter(outputstream);
            BufferedWriter bufferedwriter = new BufferedWriter(outputstreamwriter);

            String string = null;
            while ((string = bufferedreader.readLine()) != null) {
                bufferedwriter.write(string + '\n');
                bufferedwriter.flush();
            }

        } catch (Exception exception) {
            exception.printStackTrace();
        }
    }
}

SSL Debug Log

java -Djavax.net.ssl.trustStore=ca_only.jks -Djavax.net.ssl.keyStore=keystore.jks -Djavax.net.debug=ssl,handshake -Djavax.net.ssl.keyStorePassword=password -Djavax.net.ssl.trustStorePassword=password Client
keyStore is : keystore.jks
keyStore type is : jks
keyStore provider is :
init keystore
init keymanager of type SunX509
***
found key for : 1
chain [0] = [
[
  Version: V3
  Subject: CN=Server, O=Organization, ST=ON, C=CA
  Signature Algorithm: SHA1withRSA, OID = 1.2.840.113549.1.1.5

  Key:  Sun RSA public key, 2048 bits
  modulus: {snipped due to post length}
  public exponent: 65537
  Validity: [From: Wed Jul 04 11:17:50 CDT 2012,
               To: Mon Jul 04 11:17:50 CDT 2022]
  Issuer: CN=DEV2008, O=Organization, ST=ON, C=CA
  SerialNumber: [    b7ccceda 64ef4eb7]

Certificate Extensions: 4
[1]: ObjectId: 2.16.840.1.113730.1.13 Criticality=false
Extension unknown: DER encoded OCTET string =
0000: 04 1F 16 1D 4F 70 65 6E   53 53 4C 20 47 65 6E 65  ....OpenSSL Gene
0010: 72 61 74 65 64 20 43 65   72 74 69 66 69 63 61 74  rated Certificat
0020: 65                                                 e


[2]: ObjectId: 2.5.29.35 Criticality=false
AuthorityKeyIdentifier [
KeyIdentifier [
0000: B8 92 53 99 09 EB 73 6D   6D 45 8E 84 35 C5 11 77  ..S...smmE..5..w
0010: 7A 41 C9 10                                        zA..
]
]

[3]: ObjectId: 2.5.29.19 Criticality=false
BasicConstraints:[
  CA:false
  PathLen: undefined
]

[4]: ObjectId: 2.5.29.14 Criticality=false
SubjectKeyIdentifier [
KeyIdentifier [
0000: 43 EF 2E E1 B8 E6 01 C4   65 E1 E3 38 CE DA 86 C7  C.......e..8....
0010: BE 93 65 BA                                        ..e.
]
]

]
  Algorithm: [SHA1withRSA]
  Signature:
{snipped due to post length}

]
***
trustStore is: ca_only.jks
trustStore type is : jks
trustStore provider is :
init truststore
adding as trusted cert:
  Subject: CN=DEV2008, O=Organization, ST=ON, C=CA
  Issuer:  CN=DEV2008, O=Organization, ST=ON, C=CA
  Algorithm: RSA; Serial number: 0xb7ccceda64ef4eb3
  Valid from Wed Sep 10 10:10:25 CDT 2008 until Sun Sep 10 10:10:25 CDT 2028

trigger seeding of SecureRandom
done seeding SecureRandom
Ignoring unavailable cipher suite: TLS_ECDHE_RSA_WITH_AES_256_CBC_SHA
Ignoring unavailable cipher suite: TLS_DHE_RSA_WITH_AES_256_CBC_SHA
Ignoring unavailable cipher suite: TLS_ECDH_RSA_WITH_AES_256_CBC_SHA
Ignoring unsupported cipher suite: TLS_DHE_DSS_WITH_AES_128_CBC_SHA256
Ignoring unsupported cipher suite: TLS_DHE_DSS_WITH_AES_256_CBC_SHA256
Ignoring unsupported cipher suite: TLS_DHE_RSA_WITH_AES_128_CBC_SHA256
Ignoring unsupported cipher suite: TLS_ECDH_RSA_WITH_AES_128_CBC_SHA256
Ignoring unsupported cipher suite: TLS_DHE_RSA_WITH_AES_256_CBC_SHA256
Ignoring unsupported cipher suite: TLS_ECDHE_RSA_WITH_AES_256_CBC_SHA384
Ignoring unsupported cipher suite: TLS_ECDH_ECDSA_WITH_AES_256_CBC_SHA384
Ignoring unsupported cipher suite: TLS_RSA_WITH_AES_256_CBC_SHA256
Ignoring unavailable cipher suite: TLS_ECDHE_ECDSA_WITH_AES_256_CBC_SHA
Ignoring unsupported cipher suite: TLS_ECDHE_RSA_WITH_AES_128_CBC_SHA256
Ignoring unsupported cipher suite: TLS_ECDHE_ECDSA_WITH_AES_256_CBC_SHA384
Ignoring unavailable cipher suite: TLS_DHE_DSS_WITH_AES_256_CBC_SHA
Ignoring unsupported cipher suite: TLS_ECDH_RSA_WITH_AES_256_CBC_SHA384
Ignoring unsupported cipher suite: TLS_ECDHE_ECDSA_WITH_AES_128_CBC_SHA256
Ignoring unsupported cipher suite: TLS_ECDH_ECDSA_WITH_AES_128_CBC_SHA256
Ignoring unavailable cipher suite: TLS_ECDH_ECDSA_WITH_AES_256_CBC_SHA
Ignoring unavailable cipher suite: TLS_RSA_WITH_AES_256_CBC_SHA
Ignoring unsupported cipher suite: TLS_RSA_WITH_AES_128_CBC_SHA256
Allow unsafe renegotiation: false
Allow legacy hello messages: true
Is initial handshake: true
Is secure renegotiation: false
testText
%% No cached client session
*** ClientHello, TLSv1
RandomCookie:  GMT: 1388847103 bytes = { 81, 210, 193, 47, 1, 40, 31, 209, 31, 74, 153, 216, 224, 141, 29, 4, 49, 162, 216, 34, 206, 202, 42, 228, 204, 73, 106, 208 }
Session ID:  {}
Cipher Suites: [TLS_ECDHE_ECDSA_WITH_AES_128_CBC_SHA, TLS_ECDHE_RSA_WITH_AES_128_CBC_SHA, TLS_RSA_WITH_AES_128_CBC_SHA, TLS_ECDH_ECDSA_WITH_AES_128_CBC_SHA, TLS_ECDH_RSA_WITH_AES_128_CBC_SHA, TLS_DHE_RSA_WITH_AES_128_CBC_SHA, TLS_DHE_DSS_WITH_AES_128_CBC_SHA,TLS_ECDHE_ECDSA_WITH_RC4_128_SHA, TLS_ECDHE_RSA_WITH_RC4_128_SHA, SSL_RSA_WITH_RC4_128_SHA, TLS_ECDH_ECDSA_WITH_RC4_128_SHA, TLS_ECDH_RSA_WITH_RC4_128_SHA, TLS_ECDHE_ECDSA_WITH_3DES_EDE_CBC_SHA, TLS_ECDHE_RSA_WITH_3DES_EDE_CBC_SHA, SSL_RSA_WITH_3DES_EDE_CBC_SHA, TLS_ECDH_ECDSA_WITH_3DES_EDE_CBC_SHA, TLS_ECDH_RSA_WITH_3DES_EDE_CBC_SHA, SSL_DHE_RSA_WITH_3DES_EDE_CBC_SHA, SSL_DHE_DSS_WITH_3DES_EDE_CBC_SHA, SSL_RSA_WITH_RC4_128_MD5, TLS_EMPTY_RENEGOTIATION_INFO_SCSV]
Compression Methods:  { 0 }
Extension elliptic_curves, curve names: {secp256r1, sect163k1, sect163r2, secp192r1, secp224r1, sect233k1, sect233r1, sect283k1, sect283r1, secp384r1, sect409k1, sect409r1, secp521r1, sect571k1, sect5
71r1, secp160k1, secp160r1, secp160r2, sect163r1, secp192k1, sect193r1, sect193r2, secp224k1, sect239k1, secp256k1}
Extension ec_point_formats, formats: [uncompressed]
***
main, WRITE: TLSv1 Handshake, length = 149
main, READ: SSLv3 Handshake, length = 74
*** ServerHello, SSLv3
RandomCookie:  GMT: 1385163043 bytes = { 125, 48, 211, 49, 203, 23, 208, 161, 188, 43, 152, 33, 160, 32, 20, 163, 66, 19, 136, 90, 152, 42, 154, 53, 208, 175, 39, 177 }
Session ID:  {162, 201, 116, 199, 55, 245, 172, 195, 38, 102, 80, 124, 35, 60, 29, 218, 112, 86, 108, 44, 8, 212, 102, 73, 102, 68, 212, 246, 165, 233, 2, 31}
Cipher Suite: TLS_RSA_WITH_AES_128_CBC_SHA
Compression Method: 0
***
Warning: No renegotiation indication extension in ServerHello
%% Initialized:  [Session-1, TLS_RSA_WITH_AES_128_CBC_SHA]
** TLS_RSA_WITH_AES_128_CBC_SHA
main, READ: SSLv3 Handshake, length = 1980
*** Certificate chain
chain [0] = [
[
  Version: V3
  Subject: CN=Server, O=Organization, ST=ON, C=CA
  Signature Algorithm: SHA1withRSA, OID = 1.2.840.113549.1.1.5

  Key:  Sun RSA public key, 2048 bits
  modulus: {snipped due to post length}
  public exponent: 65537
  Validity: [From: Wed Jul 04 11:15:51 CDT 2012,
               To: Mon Jul 04 11:15:51 CDT 2022]
  Issuer: CN=DEV2008, O=Organization, ST=ON, C=CA
  SerialNumber: [    b7ccceda 64ef4eb6]

Certificate Extensions: 4
[1]: ObjectId: 2.16.840.1.113730.1.13 Criticality=false
Extension unknown: DER encoded OCTET string =
0000: 04 1F 16 1D 4F 70 65 6E   53 53 4C 20 47 65 6E 65  ....OpenSSL Gene
0010: 72 61 74 65 64 20 43 65   72 74 69 66 69 63 61 74  rated Certificat
0020: 65                                                 e


[2]: ObjectId: 2.5.29.35 Criticality=false
AuthorityKeyIdentifier [
KeyIdentifier [
0000: B8 92 53 99 09 EB 73 6D   6D 45 8E 84 35 C5 11 77  ..S...smmE..5..w
0010: 7A 41 C9 10                                        zA..
]
]

[3]: ObjectId: 2.5.29.19 Criticality=false
BasicConstraints:[
  CA:false
  PathLen: undefined
]

[4]: ObjectId: 2.5.29.14 Criticality=false
SubjectKeyIdentifier [
KeyIdentifier [
0000: 01 98 19 F0 74 48 DB CF   55 D0 1B 9B A3 C8 04 61  ....tH..U......a
0010: 50 03 F9 F6                                        P...
]
]

]
  Algorithm: [SHA1withRSA]
  Signature: {snipped due to post length}

]
chain [1] = [
[
  Version: V3
  Subject: CN=DEV2008, O=Organization, ST=ON, C=CA
  Signature Algorithm: SHA1withRSA, OID = 1.2.840.113549.1.1.5

  Key:  Sun RSA public key, 2048 bits
  modulus: {snipped due to post length}
  public exponent: 65537
  Validity: [From: Wed Sep 10 10:10:25 CDT 2008,
               To: Sun Sep 10 10:10:25 CDT 2028]
  Issuer: CN=DEV2008, O=Organization, ST=ON, C=CA
  SerialNumber: [    b7ccceda 64ef4eb3]

Certificate Extensions: 3
[1]: ObjectId: 2.5.29.35 Criticality=false
AuthorityKeyIdentifier [
KeyIdentifier [
0000: B8 92 53 99 09 EB 73 6D   6D 45 8E 84 35 C5 11 77  ..S...smmE..5..w
0010: 7A 41 C9 10                                        zA..
]
[CN=DEV2008, O=Organization, ST=ON, C=CA]
SerialNumber: [    b7ccceda 64ef4eb3]
]

[2]: ObjectId: 2.5.29.19 Criticality=false
BasicConstraints:[
  CA:true
  PathLen:2147483647
]

[3]: ObjectId: 2.5.29.14 Criticality=false
SubjectKeyIdentifier [
KeyIdentifier [
0000: B8 92 53 99 09 EB 73 6D   6D 45 8E 84 35 C5 11 77  ..S...smmE..5..w
0010: 7A 41 C9 10                                        zA..
]
]

]
  Algorithm: [SHA1withRSA]
  Signature: {snipped due to post length}

]
***
Found trusted certificate:
[
[
  Version: V3
  Subject: CN=DEV2008, O=Organization, ST=ON, C=CA
  Signature Algorithm: SHA1withRSA, OID = 1.2.840.113549.1.1.5

  Key:  Sun RSA public key, 2048 bits
  modulus: {snipped due to post length}
  public exponent: 65537
  Validity: [From: Wed Sep 10 10:10:25 CDT 2008,
               To: Sun Sep 10 10:10:25 CDT 2028]
  Issuer: CN=DEV2008, O=Organization, ST=ON, C=CA
  SerialNumber: [    b7ccceda 64ef4eb3]

Certificate Extensions: 3
[1]: ObjectId: 2.5.29.35 Criticality=false
AuthorityKeyIdentifier [
KeyIdentifier [
0000: B8 92 53 99 09 EB 73 6D   6D 45 8E 84 35 C5 11 77  ..S...smmE..5..w
0010: 7A 41 C9 10                                        zA..
]
[CN=DEV2008, O=Organization, ST=ON, C=CA]
SerialNumber: [    b7ccceda 64ef4eb3]
]

[2]: ObjectId: 2.5.29.19 Criticality=false
BasicConstraints:[
  CA:true
  PathLen:2147483647
]

[3]: ObjectId: 2.5.29.14 Criticality=false
SubjectKeyIdentifier [
KeyIdentifier [
0000: B8 92 53 99 09 EB 73 6D   6D 45 8E 84 35 C5 11 77  ..S...smmE..5..w
0010: 7A 41 C9 10                                        zA..
]
]

]
  Algorithm: [SHA1withRSA]
  Signature: {snipped due to post length}

]
main, READ: SSLv3 Handshake, length = 13
*** CertificateRequest
Cert Types: RSA, DSS
Cert Authorities:
<Empty>
*** ServerHelloDone
matching alias: 1
*** Certificate chain
chain [0] = [
[
  Version: V3
  Subject: CN=Server, O=Organization, ST=ON, C=CA
  Signature Algorithm: SHA1withRSA, OID = 1.2.840.113549.1.1.5

  Key:  Sun RSA public key, 2048 bits
  modulus: {snipped due to post length}
  public exponent: 65537
  Validity: [From: Wed Jul 04 11:17:50 CDT 2012,
               To: Mon Jul 04 11:17:50 CDT 2022]
  Issuer: CN=DEV2008, O=Organization, ST=ON, C=CA
  SerialNumber: [    b7ccceda 64ef4eb7]

Certificate Extensions: 4
[1]: ObjectId: 2.16.840.1.113730.1.13 Criticality=false
Extension unknown: DER encoded OCTET string =
0000: 04 1F 16 1D 4F 70 65 6E   53 53 4C 20 47 65 6E 65  ....OpenSSL Gene
0010: 72 61 74 65 64 20 43 65   72 74 69 66 69 63 61 74  rated Certificat
0020: 65                                                 e


[2]: ObjectId: 2.5.29.35 Criticality=false
AuthorityKeyIdentifier [
KeyIdentifier [
0000: B8 92 53 99 09 EB 73 6D   6D 45 8E 84 35 C5 11 77  ..S...smmE..5..w
0010: 7A 41 C9 10                                        zA..
]
]

[3]: ObjectId: 2.5.29.19 Criticality=false
BasicConstraints:[
  CA:false
  PathLen: undefined
]

[4]: ObjectId: 2.5.29.14 Criticality=false
SubjectKeyIdentifier [
KeyIdentifier [
0000: 43 EF 2E E1 B8 E6 01 C4   65 E1 E3 38 CE DA 86 C7  C.......e..8....
0010: BE 93 65 BA                                        ..e.
]
]

]
  Algorithm: [SHA1withRSA]
  Signature:
{snipped due to post length}

]
***
*** ClientKeyExchange, RSA PreMasterSecret, SSLv3
main, WRITE: SSLv3 Handshake, length = 1221
SESSION KEYGEN:
{snipped because I'm not sure if this is sensitive or not}
*** CertificateVerify
main, WRITE: SSLv3 Handshake, length = 262
main, WRITE: SSLv3 Change Cipher Spec, length = 1
*** Finished
verify_data:  { 159, 145, 181, 103, 3, 219, 244, 50, 1, 137, 254, 25, 166, 118, 40, 186, 196, 23, 254, 184, 250, 137, 29, 171, 163, 153, 126, 193, 226, 134, 145, 9, 137, 16, 90, 178 }
***
main, WRITE: SSLv3 Handshake, length = 64
main, READ: SSLv3 Alert, length = 2
main, RECV SSLv3 ALERT:  fatal, handshake_failure
%% Invalidated:  [Session-1, TLS_RSA_WITH_AES_128_CBC_SHA]
main, called closeSocket()
main, handling exception: javax.net.ssl.SSLHandshakeException: Received fatal alert: handshake_failure
javax.net.ssl.SSLHandshakeException: Received fatal alert: handshake_failure
        at sun.security.ssl.Alerts.getSSLException(Unknown Source)
        at sun.security.ssl.Alerts.getSSLException(Unknown Source)
        at sun.security.ssl.SSLSocketImpl.recvAlert(Unknown Source)
        at sun.security.ssl.SSLSocketImpl.readRecord(Unknown Source)
        at sun.security.ssl.SSLSocketImpl.performInitialHandshake(Unknown Source)
        at sun.security.ssl.SSLSocketImpl.writeRecord(Unknown Source)
        at sun.security.ssl.AppOutputStream.write(Unknown Source)
        at sun.nio.cs.StreamEncoder.writeBytes(Unknown Source)
        at sun.nio.cs.StreamEncoder.implFlushBuffer(Unknown Source)
        at sun.nio.cs.StreamEncoder.implFlush(Unknown Source)
        at sun.nio.cs.StreamEncoder.flush(Unknown Source)
        at java.io.OutputStreamWriter.flush(Unknown Source)
        at java.io.BufferedWriter.flush(Unknown Source)
        at Client.main(Client.java:33)

OpenSSL s_client state log As I mentioned above, I'm not really sure what this tool is telling me or if I am running it correctly.

openssl.exe s_client -connect {serverIP}:{serverPort} -cert client.cer -key client.key -cipher AES128-SHA -state
WARNING: can't open config file: /usr/local/ssl/openssl.cnf
Enter pass phrase for client.key:
Loading 'screen' into random state - done
CONNECTED(000000E0)
SSL_connect:before/connect initialization
SSL_connect:SSLv2/v3 write client hello A
SSL_connect:SSLv3 read server hello A
depth=1 C = CA, ST = ON, O = Organization, CN = DEV2008
verify error:num=19:self signed certificate in certificate chain
verify return:0
SSL_connect:SSLv3 read server certificate A
SSL_connect:SSLv3 read server certificate request A
SSL_connect:SSLv3 read server done A
SSL_connect:SSLv3 write client certificate A
SSL_connect:SSLv3 write client key exchange A
SSL_connect:SSLv3 write certificate verify A
SSL_connect:SSLv3 write change cipher spec A
SSL_connect:SSLv3 write finished A
SSL_connect:SSLv3 flush data
SSL_connect:SSLv3 read finished A
---
Certificate chain
 0 s:/C=CA/ST=ON/O=Organization/CN=Server
   i:/C=CA/ST=ON/O=Organization/CN=DEV2008
 1 s:/C=CA/ST=ON/O=Organization/CN=DEV2008
   i:/C=CA/ST=ON/O=Organization/CN=DEV2008
---
Server certificate
-----BEGIN CERTIFICATE-----
{snipped due to post length}
-----END CERTIFICATE-----
subject=/C=CA/ST=ON/O=Organization/CN=Server
issuer=/C=CA/ST=ON/O=Organization/CN=DEV2008
---
No client certificate CA names sent
---
SSL handshake has read 2157 bytes and written 1672 bytes
---
New, TLSv1/SSLv3, Cipher is AES128-SHA
Server public key is 2048 bit
Secure Renegotiation IS NOT supported
Compression: NONE
Expansion: NONE
SSL-Session:
    Protocol  : SSLv3
    Cipher    : AES128-SHA
    Session-ID: E6EB30E4E24114A59436063BE2A732B3CBF6F47A57AA34CFBFB584FC1517F5D9
    Session-ID-ctx:
    Master-Key: 86307078588C268CDCFCD6B9ABBD55DC8C0A61E900384D3FF99091E030EF9C831B61A880D33313D0DCC7C6688507790A
    Key-Arg   : None
    PSK identity: None
    PSK identity hint: None
    SRP username: None
    Start Time: 1405627491
    Timeout   : 300 (sec)
    Verify return code: 19 (self signed certificate in certificate chain)
---
read:errno=0
SSL3 alert write:warning:close notify

I noticed that in the CertificateRequest section of the SSL debug log, the Cert Authorities list is "". I read in one question that this is a configuration issue of the server, but that can't be the case because the current terminals work with no problems. I also read in another question that that is up to the implementation and may be allowed. I'm not sure which is true, but I am certain the the terminals are currently able to connect to the server, whereas my test client is unable to.

Do you know what I'm doing wrong such that I get and handshake_failure when I try to connect?

Thank you for any help you are able to provide.

Solution

Dan,

I notice a lot of "Ignoring unsupported xxxx protocols" in your debug. If you add;

socket.setEnabledProtocols(new String[]{"SSLv3", "TLSv1"}); 

to your code just after you create the factory, that should solve the handshake issue.

Comments

[Dan N]

I used 'socket.setEnabledProtocols(new String[]{"SSLv3"});' instead, and it solved the problem. This server can only use SSLv3, but the client starts the negotiation trying to use TLSv1 without this restriction. Once the restriction is placed, the negotiation succeeds and the session is cached. Thanks for the help!

[Yves Martin]

Just the only option NOT TO DO now Poodle attack is known