SSLEngine Handshake stuck at second loop

I’m trying to implement an SSL Handshake using SSLEngine, I need to do it both ways as a sever and as a client as well, however I’m stuck and I cannot figure it out why.

The handshake starts correctly, the Hello’s are exchanged, the keys are exchanged, but then I’m getting into a NEED_UNWRAP state.

Here is the handshake code I’m using:

    protected boolean doHandshake(InputStream inputStream, OutputStream outputStream, SSLEngine engine, Socket socket) throws IOException {

    Log.d(TAG,"About to do handshake...");
    Log.d(TAG,engine.getHandshakeStatus().toString());
    int dataSize;
    SSLEngineResult result;
    Log.d(TAG,"Line 1");
    HandshakeStatus handshakeStatus;
    Log.d(TAG,"Line 2");
    // NioSslPeer's fields myAppData and peerAppData are supposed to be large enough to hold all message data the peer
    // will send and expects to receive from the other peer respectively. Since the messages to be exchanged will usually be less
    // than 16KB long the capacity of these fields should also be smaller. Here we initialize these two local buffers
    // to be used for the handshake, while keeping client's buffers at the same size.

    if (socket!=null)
    {
        inputStream=socket.getInputStream();
        outputStream=socket.getOutputStream();
    }
    Log.d(TAG,"Line 3");
    int appBufferSize = engine.getSession().getApplicationBufferSize();
    Log.d(TAG,"Line 4");
    ByteBuffer myAppData = ByteBuffer.allocate(appBufferSize);
    Log.d(TAG,"Line 5");
    ByteBuffer peerAppData = ByteBuffer.allocate(appBufferSize);
    Log.d(TAG,"Line 6");
    try {
        myNetData.clear();
        peerNetData.clear();
    }
    catch (Exception e){Log.e(TAG,e.getMessage());}
    Log.d(TAG,"Line 7");

    Log.d(TAG,"Line 8");
    handshakeStatus = engine.getHandshakeStatus();
    Log.d(TAG,"Line 9");
    Log.d(TAG,"Before the while: " + (handshakeStatus != SSLEngineResult.HandshakeStatus.FINISHED && handshakeStatus != SSLEngineResult.HandshakeStatus.NOT_HANDSHAKING));

    byte[] buffer=new byte[16384];
    while (handshakeStatus != SSLEngineResult.HandshakeStatus.FINISHED && handshakeStatus != SSLEngineResult.HandshakeStatus.NOT_HANDSHAKING) {
        Log.d(TAG,handshakeStatus.toString());
        switch (handshakeStatus) {
        case NEED_UNWRAP:
            Log.d(TAG,"Got here...");
            buffer=new byte[16384];
            peerAppData.clear();
            int readdata=inputStream.read(buffer);
            Log.d(TAG,"Read data amount: " + readdata);
            if ( readdata < 0) {
                Log.d(TAG,"No data....");
                if (engine.isInboundDone() && engine.isOutboundDone()) {
                    return false;
                }
                try {
                    engine.closeInbound();
                } catch (SSLException e) {
                    Log.e(TAG,"This engine was forced to close inbound, without having received the proper SSL/TLS close notification message from the peer, due to end of stream.");
                }
                engine.closeOutbound();
                // After closeOutbound the engine will be set to WRAP state, in order to try to send a close message to the client.
                handshakeStatus = engine.getHandshakeStatus();
                break;
            }
           HackerService.bytesToHex(buffer);

            peerNetData.put(buffer,6,readdata-6);
            Log.d(TAG,"before data flipped...");
            peerNetData.flip();
            Log.d(TAG,"data flipped...");
            try {
                result = engine.unwrap(peerNetData, peerAppData);
                Log.d(TAG,"data unwrapped...");
                peerNetData.compact();

                Log.d(TAG,"data compacted...");
                handshakeStatus = result.getHandshakeStatus();
                Log.d(TAG,"Handshake status: " + handshakeStatus);
            } catch (SSLException sslException) {
                Log.e(TAG,"A problem was encountered while processing the data that caused the SSLEngine to abort. Will try to properly close connection..." + sslException.getMessage());
                engine.closeOutbound();
                handshakeStatus = engine.getHandshakeStatus();
                break;
            }
            switch (result.getStatus()) {
            case OK:
                break;
            case BUFFER_OVERFLOW:
                // Will occur when peerAppData's capacity is smaller than the data derived from peerNetData's unwrap.
                peerAppData = enlargeApplicationBuffer(engine, peerAppData);
                break;
            case BUFFER_UNDERFLOW:
                // Will occur either when no data was read from the peer or when the peerNetData buffer was too small to hold all peer's data.
                peerNetData = handleBufferUnderflow(engine, peerNetData);
                break;
            case CLOSED:
                if (engine.isOutboundDone()) {
                    return false;
                } else {
                    engine.closeOutbound();
                    handshakeStatus = engine.getHandshakeStatus();
                    break;
                }
            default:
                throw new IllegalStateException("Invalid SSL status: " + result.getStatus());
            }
            break;
        case NEED_WRAP:
            myNetData.clear();
            Log.d(TAG,"Enetering need wrap");
            try {
                result = engine.wrap(myAppData, myNetData);
                Log.d(TAG,"Got a result" + myAppData.toString());
                handshakeStatus = result.getHandshakeStatus();
                Log.d(TAG,"Handskes is: " + handshakeStatus.toString());

            } catch (SSLException sslException) {
                Log.e(TAG,"A problem was encountered while processing the data that caused the SSLEngine to abort. Will try to properly close connection...");
                engine.closeOutbound();
                handshakeStatus = engine.getHandshakeStatus();
                break;
            }
            switch (result.getStatus()) {
            case OK :
                Log.d(TAG,"Case WRAP, OK");
                myNetData.flip();

             //  while (myNetData.hasRemaining()) {
                    byte[] arr = new byte[myNetData.remaining()+6];
                    myNetData.get(arr,6,myNetData.remaining());
                    arr[0]=0;
                    arr[1]=3;
                    arr[2]=(byte) ((arr.length-4)/256);
                    arr[3]=(byte) ((arr.length-4)%256);
                    arr[4]=buffer[4];
                    arr[5]=buffer[5];
                    HackerService.bytesToHex(arr);
                    outputStream.write(arr);
               // }
                break;
            case BUFFER_OVERFLOW:
                Log.d(TAG,"Case WRAP,OverFlow");
                // Will occur if there is not enough space in myNetData buffer to write all the data that would be generated by the method wrap.
                // Since myNetData is set to session's packet size we should not get to this point because SSLEngine is supposed
                // to produce messages smaller or equal to that, but a general handling would be the following:
                myNetData = enlargePacketBuffer(engine, myNetData);
                break;
            case BUFFER_UNDERFLOW:
                throw new SSLException("Buffer underflow occured after a wrap. I don't think we should ever get here.");
            case CLOSED:
                try {
                    Log.d(TAG,"Before WRAP FLIP");
                    myNetData.flip();
                    Log.d(TAG,"After WRAP FLIP");
                    while (myNetData.hasRemaining()) {
                        Log.d(TAG,myNetData.toString());
                         arr = new byte[myNetData.remaining()];
                        myNetData.get(arr);
                        outputStream.write(arr);
                    }
                    // At this point the handshake status will probably be NEED_UNWRAP so we make sure that peerNetData is clear to read.
                    peerNetData.clear();
                } catch (Exception e) {
                    Log.e(TAG,"Failed to send server's CLOSE message due to socket channel's failure.");
                    handshakeStatus = engine.getHandshakeStatus();
                }
                break;
            default:
                throw new IllegalStateException("Invalid SSL status: " + result.getStatus());
            }
            break;
        case NEED_TASK:
            Log.d(TAG,"Need task");
            Runnable task;
            while ((task = engine.getDelegatedTask()) != null) {
                executor.execute(task);
            }
            handshakeStatus = engine.getHandshakeStatus();
            break;
        case FINISHED:
            break;
        case NOT_HANDSHAKING:
            break;
        default:
            throw new IllegalStateException("Invalid SSL status: " + handshakeStatus);
        }
    }
    Log.d(TAG,"Handshake completed");
    return true;

}

This is my SSLEngine creating class:

public static SSLEngine Builder(Context context) throws KeyStoreException, CertificateException, NoSuchAlgorithmException, IOException, UnrecoverableKeyException, KeyManagementException {
        InputStream openRawResource = context.getResources().openRawResource(context.getResources().getIdentifier("mykey", "raw", context.getPackageName()));
        KeyStore instance = KeyStore.getInstance("PKCS12");
        instance.load(openRawResource, "passcode".toCharArray());
        KeyManagerFactory instance2 = KeyManagerFactory.getInstance(KeyManagerFactory.getDefaultAlgorithm());
        instance2.init(instance, "passcode".toCharArray());
        SSLContext instance3 = SSLContext.getInstance("TLSv1.2");
        instance3.init(instance2.getKeyManagers(), new TrustManager[]{new TrustmanagerHelper()}, new SecureRandom());
        SSLEngine createSSLEngine = instance3.createSSLEngine();
        createSSLEngine.setNeedClientAuth(true);
        return createSSLEngine;

    }

When I’m attempting a handshake as a client. As you can see from the logs, I start in NEED_WRAP, send data to server, states gets to NEED_UNWRAP (which is correct) server responds, I parse the answer without any error, but instead of advancing to NEED_WRAP I get stuck in NEED_UNWRAP…

About to do handshake...
NEED_WRAP
Line 1
Line 2
Line 4
Line 5
Line 6
Line 7
Line 8
Line 9
Before the while: true
NEED_WRAP
Enetering need wrap
Got a resultjava.nio.HeapByteBuffer[pos=0 lim=16384 cap=16384]
Handskes is: NEED_UNWRAP
Case WRAP, OK
ByteTohex: 00030088000316030100810100007D03030E62BFCFF988.......
NEED_UNWRAP
Got here...
Read data amount: 2296   (THIS MATCHES THE NUMBER OF BYTES SENT BY THE SERVER!!!!)
ByteTohex: 000308F40003160303005B0200005703035B203DA285349B7C88A76CA6AA3.....
before data flipped...
data flipped...
data unwrapped...
data compacted...
Handshake status: NEED_UNWRAP
NEED_UNWRAP
Got here...

If I try to do the handshake as a server, logs looks like this. As you can see from the logs, the first read is fine, I respond to the client, I get the second bit of data from the client, and instead of having a NEED_WRAP and being able to carry on with the handshake I’m hit with a NEED_UNWRAP message, but of course there is no more data to be read from the client….

    About to do handshake...
    NEED_UNWRAP
    Line 1
    Line 2
    Line 3
    Line 4
    Line 5
    Line 6
    Line 7
    Line 8
    Line 9
    Before the while: true
    NEED_UNWRAP
    Got here...
06-12 23:42:14.017 7523-7620/uk.co.borconi,emil.myapp D/MyApp: Read data amount: 297
06-12 23:42:14.020 7523-7620/uk.co.borconi,emil.myapp D/MyApp: ByteTohex: 00030125000316....
    before data flipped...
    data flipped...
06-12 23:42:14.029 7523-7620/uk.co.borconi,emil.myapp D/MyApp: data unwrapped...
    data compacted...
    Handshake status: NEED_WRAP
    NEED_WRAP
    Enetering need wrap
    Got a resultjava.nio.HeapByteBuffer[pos=0 lim=16384 cap=16384]
    Handskes is: NEED_UNWRAP
    Case WRAP, OK
06-12 23:42:14.030 7523-7620/uk.co.borconi,emil.myapp D/MyApp: ByteTohex: 00030881000316.....
    NEED_UNWRAP
    Got here...
06-12 23:42:14.038 7523-7620/uk.co.borconi,emil.myapp D/MyApp: Read data amount: 132
06-12 23:42:14.039 7523-7620/uk.co.borconi,emil.myapp D/MyApp: ByteTohex: 00030080000316....
    before data flipped...
    data flipped...
06-12 23:42:14.040 7523-7620/uk.co.borconi,emil.myapp D/MyApp: data unwrapped...
    data compacted...
    Handshake status: NEED_UNWRAP
    NEED_UNWRAP
    Got here...

I did had a look at some similar questions on StackOverflow before posting, but they were mainly about order being wrong, which I think I got right in this case… I’m pretty sure I’m missing the obvious, but I just cannot seem to figure it out…

Answer

After 2 days of chasing my own tale, I have finally found the problem as described here: https://github.com/netty/netty/issues/5975

I found that our stream-based wrapper around SSLEngine doesn’t read all incoming data from the SSLEngine when there is no new incoming data from the network, so the application gets stuck waiting for incoming data. After some debugging I found out that with netty’s openssl SSLEngine unwrap seems to produce plain text data in smaller chunks (probably single TLS frames) and keeps buffering the rest of the data internally. The src buffer is fully consumed but calling unwrap again with an empty src buffer will still produce more data. This differs from what the JDK SSLEngine does in two points:

• the JDK SSLEngine consumes and produces as much data as possible in one go while the openssl one produces less output in one call
• the JDK SSLEngine doesn’t buffer encrypted data internally between calls to unwrap but “puts them back” into the src buffer

So even my code was “correct” I needed to do multiple loops so now my unwrap codes looks something like this:

peerNetData.put(buffer,6,readdata-6);
                Log.d(TAG,"before data flipped...");
                peerNetData.flip();
                Log.d(TAG,"data flipped...");
                try {
                    do {
                    result = engine.unwrap(peerNetData, peerAppData);
                    Log.d(TAG,"data unwrapped...");
                    Log.d(TAG,"Handskes is: " + result.getHandshakeStatus().toString() +" Current Status: " +result.getStatus() + " Bytes consumed: " + result.bytesConsumed() + " bytes produce: " + result.bytesProduced());
                    } while (peerNetData.hasRemaining() || result.bytesProduced()>0);
                    peerNetData.compact();


                    Log.d(TAG,"data compacted...");
                    handshakeStatus = result.getHandshakeStatus();
                    Log.d(TAG,"Handshake status: " + handshakeStatus);
                    .....................................................