users@grizzly.java.net

Re: SSL connection closed after repeated TCP open-close cycles

From: Oleksiy Stashok <Oleksiy.Stashok_at_Sun.COM>
Date: Tue, 27 Oct 2009 10:41:14 +0100

> There are two reasons which lead me to believe that the health check
> was
> related to the stack trace. The first is that I set up a local test
> where I
> run less watching the Grizzly log and run a program which does the TCP
> open-close on a regular interval (5 seconds). I could see that every
> time
> the TCP open-close fired I would get a stack trace. The second
> reason is
> that the stack trace occurs on line 426 of SSLUtils (near the top of
> doHandshake). The doRead method is called and this returns -1. This
> causes
> sslEngine.closeInbound() (which appears to cause one of the
> exceptions) then
> we hit throw new EOFException("Connection closed"), which is the other
> exception.
I see. However this exception is related to current TCP health
connection, and shouldn't affect any other existing connection.

> What's a good way to get started writing a filter to sit in front of
> SSLReadFilter?
The question here is how we can recognize, that this is not SSL, but
"health" connection?
Now, IMO, every connection, which doesn't have initialized SSL session
and returns -1 on first read attempt is "health" connection, right?

So the very first filter should check if processing connection is new
(doesn't have specific attachment) and read returns -1 - then skip
further processing.
Ok, it will work good if it's really health connection, but if not -
we need to make SSLReadFilter use data, which has been read already on
first read. To avoid copying data from one buffer to another, we need
our first filter to read data in the same buffer, which will be used
by SSLReadFilter. So we will need to borrow some logic from
SSLReadFilter.

Here I'll try to show the filter implementation how I see it, but you
can change the implementation for sure (I have created custom
SSLReadFilter to have access to some protected fields and methods, so
you can use this class instead regular SSLReadFilter implementation).

Anyway, it's just an idea.

Thanks.

WBR,
Alexey.


import com.sun.grizzly.Context;
import com.sun.grizzly.ProtocolFilter;
import com.sun.grizzly.filter.SSLReadFilter;
import com.sun.grizzly.util.SSLUtils;
import com.sun.grizzly.util.ThreadAttachment;
import com.sun.grizzly.util.WorkerThread;
import java.io.IOException;
import java.nio.ByteBuffer;
import java.nio.channels.SelectionKey;
import java.nio.channels.SocketChannel;
import javax.net.ssl.SSLEngine;

/**
  *
  */
public class CustomFilter implements ProtocolFilter {
     private final CustomSSLReadFilter sslFilter;

     public CustomFilter(CustomSSLReadFilter sslFilter) {
         this.sslFilter = sslFilter;
     }

     public boolean execute(Context ctx) throws IOException {
         // Check if there is SSL session open on the connection
         if (!isSSLSessionEstablished(ctx)) {
             final SelectionKey selectionKey = ctx.getSelectionKey();

             // Create SSL Engine to be able to initialize SSL buffers
             sslFilter.obtainSSLEngine(selectionKey);

             // Initialize SSL buffers to read data directly there
             SSLUtils.allocateThreadBuffers(sslFilter.getInputBBSize());

             final WorkerThread workerThread = (WorkerThread)
Thread.currentThread();
             ByteBuffer inputBB = workerThread.getInputBB();

             int count;
             try {
                 count = ((SocketChannel)
selectionKey.channel()).read(inputBB);
             } catch(IOException e) {
                 count = -1;
             }

             if (count == -1) {
                 // This is health connection, stop filter chain
                 return false;
             }

             // Let SSLReadFilter process handshake
             return true;
         }

         // Let SSLReadFilter process handshake
         return true;
     }



     public boolean postExecute(Context ctx) throws IOException {
         return true;
     }

     /**
      * Checks if SSL session was established
      *
      * @param ctx
      * @return
      */
     private boolean isSSLSessionEstablished(Context ctx) {
         final WorkerThread workerThread = (WorkerThread)
Thread.currentThread();
         if (workerThread.getSSLEngine() != null) {
             return true;
         }

         final SelectionKey key = ctx.getSelectionKey();
         if (key.attachment() instanceof ThreadAttachment) {
             if (((ThreadAttachment) key.attachment()).getSSLEngine() !
= null) {
                 return true;
             }
         }

         return false;
     }

     public class CustomSSLReadFilter extends SSLReadFilter {
         public int getInputBBSize() {
             return inputBBSize;
         }

         @Override
         public SSLEngine obtainSSLEngine(SelectionKey key) {
             final SSLEngine sslEngine = super.obtainSSLEngine(key);

             final WorkerThread workerThread = (WorkerThread)
Thread.currentThread();
             workerThread.setSSLEngine(sslEngine);

             final ThreadAttachment attachment =
workerThread.updateAttachment(
                     ThreadAttachment.Mode.SSL_ENGINE);
             key.attach(attachment);

             return sslEngine;
         }


     }
}


>
> Thanks again.
>
> Regards
> Brandon
>
>
>
> Oleksiy Stashok wrote:
>>
>>> Sure. We have (or will have) a server sitting on a port on the
>>> Internet.
>>> Several (could be hundreds) clients make long lived SSL connections
>>> (the
>>> server sends various kinds of commands to them). The server sits
>>> behind a
>>> load balancer so that we have many instances of the server. The load
>>> balancer uses TCP connection (an open followed by a close) as an
>>> "are you
>>> alive" check (what I've been calling a health check). We noticed
>>> that when
>>> under the balancer that the SSL connections were getting dropped
>>> (the
>>> clients automatically reconnect) far more quickly than should be (5
>>> - 15
>>> minutes for connections that should last hours). This behavior does
>>> not
>>> occur when TCP health check is not used (either another kind of
>>> health check
>>> or not under the balancer). When we began to investigate we noticed
>>> that the
>>> Grizzly logging in the SSL handshake was complaining (in the form of
>>> a stack
>>> trace) that it was getting connections that were not SSL (the health
>>> check).
>>> I do not know if this stack trace has any relationship to the
>>> dropped
>>> connections, but it is the only evidence I have to go on. As I noted
>>> earlier, the real concern here is that a malicious program could
>>> send TCP
>>> connections to our server and severely disrupt it.
>> It shouldn't be the case here. Newly accepted TCP connection should
>> not affect any existing SSL connections.
>> If your health check is just open/close, and you don't send any
>> data -
>> you'd never see any handshake problem, because you actually don't
>> send
>> any data.
>> So, IMO, the stacktrace you saw wasn't related to health check.
>>
>> WBR,
>> Alexey.
>>
>>>
>>> Thanks again.
>>> Brandon
>>>
>>>
>>>
>>> Oleksiy Stashok wrote:
>>>>
>>>> Hmm, probably I missed something in your usecase :)
>>>>
>>>>> I'm not understanding you're first statement. Do you think the TCP
>>>>> connection will interfere with existing SSL connections? I've been
>>>>> looking
>>>>> though the Grizzly code and couldn't see how this was possible.
>>>> I was just thinking, that you will have single connection, where
>>>> you'd
>>>> like to send SSL packets together with raw TCP "health" packets.
>>>> Isn't it the case?
>>>>
>>>> If not - please provide more info how it should work.
>>>>
>>>> Thank you.
>>>>
>>>> WBR,
>>>> Alexey.
>>>>
>>>>>
>>>>> Thanks.
>>>>> Brandon
>>>>>
>>>>>
>>>>>
>>>>> Oleksiy Stashok wrote:
>>>>>>
>>>>>> Hi Brandon,
>>>>>>
>>>>>>
>>>>>>> Thanks for the reply. You are correct the health check is a
>>>>>>> regular
>>>>>>> TCP
>>>>>>> connection and should not go to SSLReadFilter. I thought to
>>>>>>> write a
>>>>>>> simple
>>>>>>> example that showed the issue. But after a day, my "simple"
>>>>>>> example
>>>>>>> does not
>>>>>>> show the issue. I've attached the relevant bits from our server
>>>>>>> (hope you
>>>>>>> can wade through it).
>>>>>> Strange, I'd say once you send any "health" packet - SSL
>>>>>> connection
>>>>>> will fail. May be in "simple" example you don't send "health"
>>>>>> packets?
>>>>>> IMO we have 2 possibilities here to solve the issue:
>>>>>> 1) Add additional filters to filter-chain before SSLReadFilter,
>>>>>> to
>>>>>> handle "health packets".
>>>>>> Doable, but not the easiest solution.
>>>>>>
>>>>>> 2) Send "health" packets via SSL.
>>>>>> More consistent way, easier to implement, but more expensive
>>>>>> from
>>>>>> perf. side.
>>>>>>
>>>>>> WBR,
>>>>>> Alexey.
>>>>>>
>>>>>>>
>>>>>>> Regards
>>>>>>> Brandon
>>>>>>>
>>>>>>> http://www.nabble.com/file/p26033264/
>>>>>>> brivo_grizzly_initialization.zip
>>>>>>> brivo_grizzly_initialization.zip
>>>>>>>
>>>>>>>
>>>>>>>
>>>>>>> Oleksiy Stashok wrote:
>>>>>>>>
>>>>>>>> Hi Brandon,
>>>>>>>>
>>>>>>>>> I'm working on a Grizzly server (using 1.9.18). I have a
>>>>>>>>> number of
>>>>>>>>> long
>>>>>>>>> lived SSL connected clients. I'm trying to run this
>>>>>>>>> configuration
>>>>>>>>> under a
>>>>>>>>> load balancer. The balancer uses a health check that consists
>>>>>>>>> of a
>>>>>>>>> TCP
>>>>>>>>> open-close cycle. It seems that after a number (exact count
>>>>>>>>> undetermined) of
>>>>>>>>> these health check cycles one (or more - undetermined) of the
>>>>>>>>> SSL
>>>>>>>>> connected
>>>>>>>>> clients gets its connection closed. The health check hits the
>>>>>>>>> same
>>>>>>>>> port as
>>>>>>>>> the SSL client. I'm using the SSLReadFilter and the health
>>>>>>>>> check
>>>>>>>>> causes the
>>>>>>>>> filter to start an SSL handshake which fails (and a stack
>>>>>>>>> trace is
>>>>>>>>> thrown -
>>>>>>>>> see below).
>>>>>>>>>
>>>>>>>>> Any pointers to how to diagnose this issue would be greatly
>>>>>>>>> appreciated. In
>>>>>>>>> particular, is there a way to put a filter in front of the
>>>>>>>>> SSLReadFilter
>>>>>>>>> that would catch the health check and throw it away?
>>>>>>>> Just to understand the usecase better... Health check packets
>>>>>>>> are
>>>>>>>> not
>>>>>>>> secured, right, so they shouldn't come to SSLReadFilter?
>>>>>>>> Can you pls. share the Grizzly code, how you initialize the
>>>>>>>> server?
>>>>>>>>
>>>>>>>> Thanks.
>>>>>>>>
>>>>>>>> WBR,
>>>>>>>> Alexey.
>>>>>>>>
>>>>>>>>>
>>>>>>>>> Thanks
>>>>>>>>> Brandon
>>>>>>>>>
>>>>>>>>> Exception thrown when TCP open-close cycle hits the
>>>>>>>>> SSLReadFilter:
>>>>>>>>>
>>>>>>>>> javax.net.ssl.SSLException: Inbound closed before receiving
>>>>>>>>> peer's
>>>>>>>>> close_notify: possible truncation attack?
>>>>>>>>> at
>>>>>>>>> com
>>>>>>>>> .sun.net.ssl.internal.ssl.Alerts.getSSLException(Alerts.java:
>>>>>>>>> 166)
>>>>>>>>> at
>>>>>>>>> com
>>>>>>>>> .sun
>>>>>>>>> .net.ssl.internal.ssl.SSLEngineImpl.fatal(SSLEngineImpl.java:
>>>>>>>>> 1356)
>>>>>>>>> at
>>>>>>>>> com
>>>>>>>>> .sun
>>>>>>>>> .net.ssl.internal.ssl.SSLEngineImpl.fatal(SSLEngineImpl.java:
>>>>>>>>> 1324)
>>>>>>>>> at
>>>>>>>>> com
>>>>>>>>> .sun
>>>>>>>>> .net
>>>>>>>>> .ssl
>>>>>>>>> .internal.ssl.SSLEngineImpl.closeInbound(SSLEngineImpl.java:
>>>>>>>>> 1263)
>>>>>>>>> at com.sun.grizzly.util.SSLUtils.doHandshake(SSLUtils.java:
>>>>>>>>> 426)
>>>>>>>>> at com.sun.grizzly.util.SSLUtils.doHandshake(SSLUtils.java:
>>>>>>>>> 390)
>>>>>>>>> at
>>>>>>>>> com
>>>>>>>>> .sun
>>>>>>>>> .grizzly.filter.SSLReadFilter.doHandshake(SSLReadFilter.java:
>>>>>>>>> 242)
>>>>>>>>> at
>>>>>>>>> com
>>>>>>>>> .sun.grizzly.filter.SSLReadFilter.execute(SSLReadFilter.java:
>>>>>>>>> 173)
>>>>>>>>> at
>>>>>>>>> com
>>>>>>>>> .brivo
>>>>>>>>> .commandserv
>>>>>>>>> .communication
>>>>>>>>> .EnhancedSSLReadFilter.execute(EnhancedSSLReadFilter.java:40)
>>>>>>>>> at
>>>>>>>>> com
>>>>>>>>> .sun
>>>>>>>>> .grizzly
>>>>>>>>> .DefaultProtocolChain
>>>>>>>>> .executeProtocolFilter(DefaultProtocolChain.java:135)
>>>>>>>>> at
>>>>>>>>> com
>>>>>>>>> .sun
>>>>>>>>> .grizzly
>>>>>>>>> .DefaultProtocolChain.execute(DefaultProtocolChain.java:
>>>>>>>>> 102)
>>>>>>>>> at
>>>>>>>>> com
>>>>>>>>> .sun
>>>>>>>>> .grizzly
>>>>>>>>> .DefaultProtocolChain.execute(DefaultProtocolChain.java:
>>>>>>>>> 88)
>>>>>>>>> at
>>>>>>>>> com
>>>>>>>>> .sun
>>>>>>>>> .grizzly
>>>>>>>>> .ProtocolChainContextTask
>>>>>>>>> .doCall(ProtocolChainContextTask.java:
>>>>>>>>> 53)
>>>>>>>>> at
>>>>>>>>> com
>>>>>>>>> .sun
>>>>>>>>> .grizzly
>>>>>>>>> .SelectionKeyContextTask.call(SelectionKeyContextTask.java:
>>>>>>>>> 57)
>>>>>>>>> at com.sun.grizzly.ContextTask.run(ContextTask.java:69)
>>>>>>>>> at
>>>>>>>>> com.sun.grizzly.util.FixedThreadPool
>>>>>>>>> $BasicWorker.dowork(FixedThreadPool.java:379)
>>>>>>>>> at
>>>>>>>>> com.sun.grizzly.util.FixedThreadPool
>>>>>>>>> $BasicWorker.run(FixedThreadPool.java:360)
>>>>>>>>> at java.lang.Thread.run(Thread.java:595)
>>>>>>>>> Oct 22, 2009 1:52:43 PM com.sun.grizzly.filter.SSLReadFilter
>>>>>>>>> log
>>>>>>>>> FINE: doHandshake
>>>>>>>>> java.io.EOFException: Connection closed
>>>>>>>>> at com.sun.grizzly.util.SSLUtils.doHandshake(SSLUtils.java:
>>>>>>>>> 433)
>>>>>>>>> at com.sun.grizzly.util.SSLUtils.doHandshake(SSLUtils.java:
>>>>>>>>> 390)
>>>>>>>>> at
>>>>>>>>> com
>>>>>>>>> .sun
>>>>>>>>> .grizzly.filter.SSLReadFilter.doHandshake(SSLReadFilter.java:
>>>>>>>>> 242)
>>>>>>>>> at
>>>>>>>>> com
>>>>>>>>> .sun.grizzly.filter.SSLReadFilter.execute(SSLReadFilter.java:
>>>>>>>>> 173)
>>>>>>>>> at
>>>>>>>>> com
>>>>>>>>> .brivo
>>>>>>>>> .commandserv
>>>>>>>>> .communication
>>>>>>>>> .EnhancedSSLReadFilter.execute(EnhancedSSLReadFilter.java:40)
>>>>>>>>> at
>>>>>>>>> com
>>>>>>>>> .sun
>>>>>>>>> .grizzly
>>>>>>>>> .DefaultProtocolChain
>>>>>>>>> .executeProtocolFilter(DefaultProtocolChain.java:135)
>>>>>>>>> at
>>>>>>>>> com
>>>>>>>>> .sun
>>>>>>>>> .grizzly
>>>>>>>>> .DefaultProtocolChain.execute(DefaultProtocolChain.java:
>>>>>>>>> 102)
>>>>>>>>> at
>>>>>>>>> com
>>>>>>>>> .sun
>>>>>>>>> .grizzly
>>>>>>>>> .DefaultProtocolChain.execute(DefaultProtocolChain.java:
>>>>>>>>> 88)
>>>>>>>>> at
>>>>>>>>> com
>>>>>>>>> .sun
>>>>>>>>> .grizzly
>>>>>>>>> .ProtocolChainContextTask
>>>>>>>>> .doCall(ProtocolChainContextTask.java:
>>>>>>>>> 53)
>>>>>>>>> at
>>>>>>>>> com
>>>>>>>>> .sun
>>>>>>>>> .grizzly
>>>>>>>>> .SelectionKeyContextTask.call(SelectionKeyContextTask.java:
>>>>>>>>> 57)
>>>>>>>>> at com.sun.grizzly.ContextTask.run(ContextTask.java:69)
>>>>>>>>> at
>>>>>>>>> com.sun.grizzly.util.FixedThreadPool
>>>>>>>>> $BasicWorker.dowork(FixedThreadPool.java:379)
>>>>>>>>> at
>>>>>>>>> com.sun.grizzly.util.FixedThreadPool
>>>>>>>>> $BasicWorker.run(FixedThreadPool.java:360)
>>>>>>>>> at java.lang.Thread.run(Thread.java:595)
>>>>>>>>>
>>>>>>>>> --
>>>>>>>>> View this message in context:
>>>>>>>>> http://www.nabble.com/SSL-connection-closed-after-repeated-TCP-open-close-cycles-tp26016355p26016355.html
>>>>>>>>> Sent from the Grizzly - Users mailing list archive at
>>>>>>>>> Nabble.com.
>>>>>>>>>
>>>>>>>>>
>>>>>>>>> ---------------------------------------------------------------------
>>>>>>>>> To unsubscribe, e-mail: users-unsubscribe_at_grizzly.dev.java.net
>>>>>>>>> For additional commands, e-mail: users-help_at_grizzly.dev.java.net
>>>>>>>>>
>>>>>>>>
>>>>>>>>
>>>>>>>> ---------------------------------------------------------------------
>>>>>>>> To unsubscribe, e-mail: users-unsubscribe_at_grizzly.dev.java.net
>>>>>>>> For additional commands, e-mail: users-
>>>>>>>> help_at_grizzly.dev.java.net
>>>>>>>>
>>>>>>>>
>>>>>>>>
>>>>>>>
>>>>>>> --
>>>>>>> View this message in context:
>>>>>>> http://www.nabble.com/SSL-connection-closed-after-repeated-TCP-open-close-cycles-tp26016355p26033264.html
>>>>>>> Sent from the Grizzly - Users mailing list archive at
>>>>>>> Nabble.com.
>>>>>>>
>>>>>>>
>>>>>>> ---------------------------------------------------------------------
>>>>>>> To unsubscribe, e-mail: users-unsubscribe_at_grizzly.dev.java.net
>>>>>>> For additional commands, e-mail: users-help_at_grizzly.dev.java.net
>>>>>>>
>>>>>>
>>>>>>
>>>>>> ---------------------------------------------------------------------
>>>>>> To unsubscribe, e-mail: users-unsubscribe_at_grizzly.dev.java.net
>>>>>> For additional commands, e-mail: users-help_at_grizzly.dev.java.net
>>>>>>
>>>>>>
>>>>>>
>>>>>
>>>>> --
>>>>> View this message in context:
>>>>> http://www.nabble.com/SSL-connection-closed-after-repeated-TCP-open-close-cycles-tp26016355p26061227.html
>>>>> Sent from the Grizzly - Users mailing list archive at Nabble.com.
>>>>>
>>>>>
>>>>> ---------------------------------------------------------------------
>>>>> To unsubscribe, e-mail: users-unsubscribe_at_grizzly.dev.java.net
>>>>> For additional commands, e-mail: users-help_at_grizzly.dev.java.net
>>>>>
>>>>
>>>>
>>>> ---------------------------------------------------------------------
>>>> To unsubscribe, e-mail: users-unsubscribe_at_grizzly.dev.java.net
>>>> For additional commands, e-mail: users-help_at_grizzly.dev.java.net
>>>>
>>>>
>>>>
>>>
>>> --
>>> View this message in context:
>>> http://www.nabble.com/SSL-connection-closed-after-repeated-TCP-open-close-cycles-tp26016355p26061792.html
>>> Sent from the Grizzly - Users mailing list archive at Nabble.com.
>>>
>>>
>>> ---------------------------------------------------------------------
>>> To unsubscribe, e-mail: users-unsubscribe_at_grizzly.dev.java.net
>>> For additional commands, e-mail: users-help_at_grizzly.dev.java.net
>>>
>>
>>
>> ---------------------------------------------------------------------
>> To unsubscribe, e-mail: users-unsubscribe_at_grizzly.dev.java.net
>> For additional commands, e-mail: users-help_at_grizzly.dev.java.net
>>
>>
>>
>
> --
> View this message in context: http://www.nabble.com/SSL-connection-closed-after-repeated-TCP-open-close-cycles-tp26016355p26063806.html
> Sent from the Grizzly - Users mailing list archive at Nabble.com.
>
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: users-unsubscribe_at_grizzly.dev.java.net
> For additional commands, e-mail: users-help_at_grizzly.dev.java.net
>