FISH-631 Prevent infinite loop when using TLS 1.3

[Pandrex247]

Under certain conditions when using TLS 1.3 and JDK11, an infinite loop can occur during handshaking (until it times out anyway).
This appears to be in some way related to the behaviour of TLS 1.3 not requiring a closeNotify to be sent (the issue disappears when the system property to bring back the old behaviour is active).

Following the logic of the unwrapAll method and the output of the log, it appears to occur when trying to gracefully terminate the SSL connection - I'm not really sure why it's trying to handshake to close a connection but that's a separate issue and likely just a gap in my knowledge.

The flow of things goes as follows:

• Websocket connection gets established, following a successful handshake
• It receives some further data and goes into SSLBaseFilter.handleRead -> SSLBaseFilter.unwrapAll (I believe line 293, since the next log messages are to with unwrap rather than doHandshakeStep)
• Enter the unwrapAll loop
• First unwrap returns: Status = OK HandshakeStatus = NOT_HANDSHAKING
• Since it’s not handshaking and there is no error, it skips the handshaking block (lines 408-420) enters the switch at line 422, see’s that the response is OK and that there is some input remaining as it only breaks the switch rather than the whole do while (line 424)
• Second unwrap returns: Status = CLOSED HandshakeStatus = NEED_WRAP
• Since it is now apparently handshaking, passes the check at line 408, and as the status is CLOSED goes to execute the silentRehandshake method.
• The silentRehandshake attempts to perform a handshake via doHandshakeSync, specifically line 576/577, before it enters the do while loop at line 579.
• Since the handshake status is NEED_WRAP it attempts to wrap (line 668) and gets a result of Status = OK HandshakeStatus = NEED_WRAP
• Without my change, it then loops on this until the handshake timeout expires, never returning to doHandshakeSync (line 576/577)

Presumably the other side has closed the connection but hasn't sent a closeNotify, causing this side (Payara in this case) to continually attempt to handshake with it on a no longer active connection. Again, I'm not clear on how the current graceful SSL connection termination is meant to work and why handshaking is a part of this, but this added change appears to work (even if it is a bit brutal in essentially killing the connection dead) - more graceful solutions are likely available.

Example log for reference (line numbers may be slightly off in a couple of places due to Payara having a few unsynced changes):

[2021-01-13T14:38:00.945+0000] [] [INFO] [] [foo.bar.blip.blop.WebsocketClientSessionHandler] [tid: _ThreadID=146 _ThreadName=__ejb-thread-pool11] [timeMillis: 1610548680945] [levelValue: 800] Websocket connection to wss://example.net/ws/v1/subscriptions?subId=5f6c6575546668007f998efe established.

[2021-01-13T14:38:00.953+0000] [] [FINE] [] [org.glassfish.grizzly.ssl.SSLConnectionContext] [tid: _ThreadID=381 _ThreadName=Grizzly(1)] [timeMillis: 1610548680953] [levelValue: 500] [CLASSNAME: org.glassfish.grizzly.ssl.SSLConnectionContext] [METHODNAME: unwrap] unwrap engine: sun.security.ssl.SSLEngineImpl@71d2caa5 input: ByteBufferWrapper (1457684535) [visible=[java.nio.HeapByteBuffer[pos=0 lim=128 cap=33418]]] output: HeapBuffer (378573741) [pos=0 lim=25056 cap=25056]

[2021-01-13T14:38:00.953+0000] [] [FINE] [] [org.glassfish.grizzly.ssl.SSLConnectionContext] [tid: _ThreadID=381 _ThreadName=Grizzly(1)] [timeMillis: 1610548680953] [levelValue: 500] [CLASSNAME: org.glassfish.grizzly.ssl.SSLConnectionContext] [METHODNAME: unwrap] [[
  unwrap done engine: sun.security.ssl.SSLEngineImpl@71d2caa5 result: Status = OK HandshakeStatus = NOT_HANDSHAKING
bytesConsumed = 104 bytesProduced = 82 input: ByteBufferWrapper (1457684535) [visible=[java.nio.HeapByteBuffer[pos=104 lim=128 cap=33418]]] output: HeapBuffer (378573741) [pos=82 lim=25056 cap=25056]]]

[2021-01-13T14:38:00.953+0000] [] [FINE] [] [org.glassfish.grizzly.ssl.SSLConnectionContext] [tid: _ThreadID=381 _ThreadName=Grizzly(1)] [timeMillis: 1610548680953] [levelValue: 500] [CLASSNAME: org.glassfish.grizzly.ssl.SSLConnectionContext] [METHODNAME: unwrap] unwrap engine: sun.security.ssl.SSLEngineImpl@71d2caa5 input: ByteBufferWrapper (1457684535) [visible=[java.nio.HeapByteBuffer[pos=104 lim=128 cap=33418]]] output: HeapBuffer (378573741) [pos=82 lim=25138 cap=25138]

[2021-01-13T14:38:00.953+0000] [] [FINE] [] [org.glassfish.grizzly.ssl.SSLConnectionContext] [tid: _ThreadID=381 _ThreadName=Grizzly(1)] [timeMillis: 1610548680953] [levelValue: 500] [CLASSNAME: org.glassfish.grizzly.ssl.SSLConnectionContext] [METHODNAME: unwrap] [[
  unwrap done engine: sun.security.ssl.SSLEngineImpl@71d2caa5 result: Status = CLOSED HandshakeStatus = NEED_WRAP
bytesConsumed = 24 bytesProduced = 0 input: ByteBufferWrapper (1457684535) [visible=[java.nio.HeapByteBuffer[pos=128 lim=128 cap=33418]]] output: HeapBuffer (378573741) [pos=82 lim=25138 cap=25138]]]

[2021-01-13T14:38:00.953+0000] [] [FINEST] [] [org.glassfish.grizzly.ssl.SSLBaseFilter] [tid: _ThreadID=381 _ThreadName=Grizzly(1)] [timeMillis: 1610548680953] [levelValue: 300] [CLASSNAME: org.glassfish.grizzly.ssl.SSLBaseFilter] [METHODNAME: doHandshakeStep] Loop Engine: sun.security.ssl.SSLEngineImpl@71d2caa5 handshakeStatus=NEED_WRAP

[2021-01-13T14:38:00.953+0000] [] [FINEST] [] [org.glassfish.grizzly.ssl.SSLBaseFilter] [tid: _ThreadID=381 _ThreadName=Grizzly(1)] [timeMillis: 1610548680953] [levelValue: 300] [CLASSNAME: org.glassfish.grizzly.ssl.SSLBaseFilter] [METHODNAME: doHandshakeStep] NEED_WRAP Engine: sun.security.ssl.SSLEngineImpl@71d2caa5

[2021-01-13T14:38:00.953+0000] [] [FINE] [] [org.glassfish.grizzly.ssl.SSLConnectionContext] [tid: _ThreadID=381 _ThreadName=Grizzly(1)] [timeMillis: 1610548680953] [levelValue: 500] [CLASSNAME: org.glassfish.grizzly.ssl.SSLConnectionContext] [METHODNAME: wrap] wrap engine: sun.security.ssl.SSLEngineImpl@71d2caa5 input: ByteBufferWrapper (546389043) [visible=[java.nio.HeapByteBuffer[pos=0 lim=0 cap=0]]] output: ByteBufferWrapper (1412516464) [visible=[java.nio.HeapByteBuffer[pos=0 lim=33418 cap=33418]]]

[2021-01-13T14:38:00.954+0000] [] [FINE] [] [org.glassfish.grizzly.ssl.SSLConnectionContext] [tid: _ThreadID=381 _ThreadName=Grizzly(1)] [timeMillis: 1610548680954] [levelValue: 500] [CLASSNAME: org.glassfish.grizzly.ssl.SSLConnectionContext] [METHODNAME: wrap] [[
  wrap done engine: sun.security.ssl.SSLEngineImpl@71d2caa5 result: Status = OK HandshakeStatus = NEED_WRAP
bytesConsumed = 0 bytesProduced = 0 input: ByteBufferWrapper (546389043) [visible=[java.nio.HeapByteBuffer[pos=0 lim=0 cap=0]]] output: ByteBufferWrapper (1412516464) [visible=[java.nio.HeapByteBuffer[pos=0 lim=33418 cap=33418]]]]]

[2021-01-13T14:38:00.954+0000] [] [FINER] [] [org.glassfish.grizzly.ssl.SSLBaseFilter] [tid: _ThreadID=381 _ThreadName=Grizzly(1)] [timeMillis: 1610548680954] [levelValue: 400] [CLASSNAME: org.glassfish.grizzly.ssl.SSLBaseFilter] [METHODNAME: doHandshakeStep] Inbound connection is closed, cancelling handshake to avoid infinite loop

[2021-01-13T14:38:00.955+0000] [] [INFO] [] [foo.bar.blip.blop.PubSubWebsocketClient] [tid: _ThreadID=381 _ThreadName=Grizzly(1)] [timeMillis: 1610548680955] [levelValue: 800] [PUB-SUB Websocket Client] Session for subscription ID : 5f6c6575546668007f998efe was close. Reason: Closed abnormally..

[2021-01-13T14:38:00.956+0000] [] [FINE] [] [org.glassfish.grizzly.ssl.SSLBaseFilter] [tid: _ThreadID=381 _ThreadName=Grizzly(1)] [timeMillis: 1610548680956] [levelValue: 500] [CLASSNAME: org.glassfish.grizzly.ssl.SSLBaseFilter] [METHODNAME: silentRehandshake] [[
  Error during graceful ssl connection close
javax.net.ssl.SSLException: SSL wrap error: Inbound connection is closed
	at org.glassfish.grizzly.ssl.SSLBaseFilter.doHandshakeStep(SSLBaseFilter.java:685)
	at org.glassfish.grizzly.ssl.SSLFilter.doHandshakeStep(SSLFilter.java:308)
	at org.glassfish.grizzly.ssl.SSLBaseFilter.doHandshakeSync(SSLBaseFilter.java:583)
	at org.glassfish.grizzly.ssl.SSLBaseFilter.silentRehandshake(SSLBaseFilter.java:807)
	at org.glassfish.grizzly.ssl.SSLBaseFilter.unwrapAll(SSLBaseFilter.java:415)
	at org.glassfish.grizzly.ssl.SSLBaseFilter.handleRead(SSLBaseFilter.java:297)
	at org.glassfish.grizzly.filterchain.ExecutorResolver$9.execute(ExecutorResolver.java:95)
	at org.glassfish.grizzly.filterchain.DefaultFilterChain.executeFilter(DefaultFilterChain.java:260)
	at org.glassfish.grizzly.filterchain.DefaultFilterChain.executeChainPart(DefaultFilterChain.java:177)
	at org.glassfish.grizzly.filterchain.DefaultFilterChain.execute(DefaultFilterChain.java:109)
	at org.glassfish.grizzly.filterchain.DefaultFilterChain.process(DefaultFilterChain.java:88)
	at org.glassfish.grizzly.ProcessorExecutor.execute(ProcessorExecutor.java:53)
	at org.glassfish.grizzly.nio.transport.TCPNIOTransport.fireIOEvent(TCPNIOTransport.java:524)
	at org.glassfish.grizzly.strategies.AbstractIOStrategy.fireIOEvent(AbstractIOStrategy.java:89)
	at org.glassfish.grizzly.strategies.WorkerThreadIOStrategy.run0(WorkerThreadIOStrategy.java:94)
	at org.glassfish.grizzly.strategies.WorkerThreadIOStrategy.access$100(WorkerThreadIOStrategy.java:33)
	at org.glassfish.grizzly.strategies.WorkerThreadIOStrategy$WorkerThreadRunnable.run(WorkerThreadIOStrategy.java:114)
	at org.glassfish.grizzly.threadpool.AbstractThreadPool$Worker.doWork(AbstractThreadPool.java:569)
	at org.glassfish.grizzly.threadpool.AbstractThreadPool$Worker.run(AbstractThreadPool.java:549)
	at java.base/java.lang.Thread.run(Thread.java:834)
]]

Signed-off-by: Andrew Pielage [email protected]

[Cousjava]

Copyright year needs updating