users@grizzly.java.net

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

From: bjtb <brandon.booth_at_brivo.com>
Date: Mon, 26 Oct 2009 10:20:31 -0700 (PDT)

Hi Alexy

I couldn't see how the TCP connection would affect existing SSL connections
either, I just don't have much evidence to go on. So I'm looking into things
that seem unusual as a way to get a sense of what's going on.

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.

What's a good way to get started writing a filter to sit in front of
SSLReadFilter?

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.