Android NIO server SSL handshake hangs

[jkeljo]

Observed on Android 4.2.2 on Verizon Galaxy Nexus, also 4.0.4 on Rikomagic MK802II. Restlet versions 2.1 and 2.2RC2.

Using org.restlet.ext.nio.HttpsServerHelper to provide an HTTPS server on Android. Incoming connections hang at the SSL handshake. The issue is that SSLEngine on Android never reaches FINISHED state -- it just goes directly from NEED_WRAP to NOT_HANDSHAKING. (There's actually a @KnownFailure annotation on one of the unit tests for SSLEngine to that effect.)

Here's FINEST log output starting immediately after the client sends Handshake Finished:

02-26 07:27:24.323 17976 17996 W System.err: Handling SSL result: OK
02-26 07:27:24.323 17976 17996 W System.err: Handling SSL handshake: NEED_WRAP
02-26 07:27:24.323 17976 17996 W System.err: InboundWay#setIoState: IDLE
02-26 07:27:24.323 17976 17996 W System.err: OutboundWay#setIoState: READY
02-26 07:27:24.323 17976 17996 W System.err: 326 bytes filled into buffer
02-26 07:27:24.323 17976 17996 W System.err: Ending process of buffer java.nio.ReadWriteHeapByteBuffer, status: capacity=16384 position=0 limit=16384, FILLING, true. Result: 0, try again: true, can loop: false, total filled: 326
02-26 07:27:24.323 17976 17996 W System.err: Handling SSL result: OK
02-26 07:27:24.323 17976 17996 W System.err: Handling SSL handshake: NEED_WRAP
02-26 07:27:24.331 17976 17996 W System.err: Inbound way selected. Done for : IDLE, START, java.nio.ReadWriteHeapByteBuffer, status: capacity=16384 position=0 limit=16384, FILLING, true
02-26 07:27:24.331 17976 17996 W System.err: Entering into a connection READY loop
02-26 07:27:24.331 17976 17996 W System.err: Processing IO for outbound way: READY, IDLE, java.nio.ReadWriteHeapByteBuffer, status: capacity=16384 position=0 limit=0, DRAINING, true
02-26 07:27:24.331 17976 17996 W System.err: Beginning process of buffer java.nio.ReadWriteHeapByteBuffer, status: capacity=16384 position=0 limit=0, DRAINING, true
02-26 07:27:24.331 17976 17996 W System.err: Beginning process of buffer java.nio.ReadWriteHeapByteBuffer, status: capacity=18437 position=0 limit=18437, FILLING, true
02-26 07:27:24.331 17976 17996 W System.err: 0 bytes drained from buffer at pre-processing, 18437 remaining bytes

The first call to wrap() produces 6 bytes and returns NEED_WRAP. WireShark shows this is a Change Cipher Spec record:

02-26 07:27:24.331 17976 17996 W System.err: Filling buffer java.nio.ReadWriteHeapByteBuffer, status: capacity=18437 position=0 limit=18437, FILLING, true
02-26 07:27:24.331 17976 17996 W System.err: SSL engine result: SSLEngineReport: Status = OK  HandshakeStatus = NEED_WRAP
02-26 07:27:24.331 17976 17996 W System.err:                  bytesConsumed = 0 bytesProduced = 6
02-26 07:27:24.331 17976 17996 W System.err: SSL connection: OPEN | true | Interest= READ , Ready=READ , Canceling=false | net.randominseattle.photoframe.util.restlet.AndroidWrapperSSLEngine@42cb8bf0 | null
02-26 07:27:24.331 17976 17996 W System.err: 6 bytes filled into buffer

The second call to wrap() produces 53 bytes, which Wireshark shows is a Finished record. However, handshakeStatus is now NOT_HANDSHAKING (on J2SE it would be FINISHED), so Restlet doesn't know to finish the handshake:

02-26 07:27:24.331 17976 17996 W System.err: Filling buffer java.nio.ReadWriteHeapByteBuffer, status: capacity=18437 position=6 limit=18437, FILLING, false
02-26 07:27:24.331 17976 17996 W System.err: SSL engine result: SSLEngineReport: Status = OK  HandshakeStatus = NOT_HANDSHAKING
02-26 07:27:24.339 17976 17996 W System.err:                  bytesConsumed = 0 bytesProduced = 53
02-26 07:27:24.339 17976 17996 W System.err: SSL connection: OPEN | true | Interest= READ , Ready=READ , Canceling=false | net.randominseattle.photoframe.util.restlet.AndroidWrapperSSLEngine@42cb8bf0 | SSLEngineReport: Status = OK  HandshakeStatus = NEED_WRAP
02-26 07:27:24.339 17976 17996 W System.err:                  bytesConsumed = 0 bytesProduced = 6
02-26 07:27:24.339 17976 17996 W System.err: 53 bytes filled into buffer

Restlet then gets into a loop of calling wrap() with empty buffers. On J2SE that would return immediately, but on Android it happily encrypts them, making Restlet spew packets until the client resets the connection:

02-26 07:27:24.339 17976 17996 W System.err: Filling buffer java.nio.ReadWriteHeapByteBuffer, status: capacity=18437 position=59 limit=18437, FILLING, false
02-26 07:27:24.339 17976 17996 W System.err: SSL engine result: SSLEngineReport: Status = OK  HandshakeStatus = NOT_HANDSHAKING
02-26 07:27:24.339 17976 17996 W System.err:                  bytesConsumed = 0 bytesProduced = 37
... over and over again ...

So, there are two problems:

1. Android SSLEngine goes directly from NEED_WRAP to NOT_HANDSHAKING, instead of FINISHED like J2SE
2. Android SSLEngine happily encrypts an empty block. J2SE returns BUFFER_OVERFLOW, 0 bytes consumed, 0 bytes produced.

[jkeljo]

I'm able to work around this issue and achieve a successful SSL connection by providing my own SslContextFactory that wraps SSLEngine and modifies the behavior of wrap() to behave properly. I'd be happy to write a more direct workaround in Restlet itself, but I can't seem to make the build go. (See #851)

[jlouvel]

Thanks for the report and investigations.

Could you provide a pull request or suggest changes via a patch while we resolve the Ant build issues?

I would really like to have your fixes go into 2.2 RC4 before 2.2.0.

[jkeljo]

Sure. If necessary I'll hack the Ant build to skip the unit tests. I probably won't have time to work on this until Wednesday.

[jlouvel]

Sounds good. You can check the build.properties to turn off the unit test, or add a custom.properties file (ignored by Git).

[jlouvel]

Closing this "parent" issue.