users@grizzly.java.net

Re: SSLEngine BUFFER_UNDERFLOW & EOFException

From: Tom Magowan <tom.magowan_at_googlemail.com>
Date: Thu, 3 Sep 2009 08:40:12 +0100

Just in case you were wondering what happened with this issue - Alexey
tracked the problem down, and the fix, I am told, will be going into the
1.9.18 release. Thanks Alexey!
Kind Regards,
Tom

On Tue, Sep 1, 2009 at 5:26 PM, Oleksiy Stashok <Oleksiy.Stashok_at_sun.com>wrote:

> Hi Tom,
> please send me the code to reproduce the issue - I'll take a look ASAP.
> Today we're going to release 1.9.18 to support GFv3 integration, but if we
> will confirm the issue - we will backport it to 1.9.18 branch.
>
> Thank you.
>
> WBR,
> Alexey.
>
> I have been testing with the 1.9.18-M2 release, and the BUFFER_UNDERFLOW
> EOFException is fixed.
>
> However, occasionally it seems that reading the underlying (http11)
> GrizzlyInputStream stops abruptly. I am using a Jersey 1.0.2 servlet that is
> invoking the read on the InputStream. To be precise it is the following
> Jersey
> class: AbstractMessageReaderWriterProvider.readFromAsString(AbstractMessageReaderWriterProvider.java:89).
> This will only finish reading the InputStream when -1 is returned, as you
> would expect. I think (but I am not sure) that -1 is being returned from the
> InputStream read method, when in fact there is more data to be read. This
> only seems to happen on a BUFFER_UNDERFLOW, although it does not happen all
> the time.
>
> I have a trace log that I will send to you directly. Hopefully it will help
> diagnose the issue.
>
> Again, any help is appreciated!
>
> Kind Regards,
> Tom
>
> On Fri, Aug 21, 2009 at 3:41 PM, Oleksiy Stashok <Oleksiy.Stashok_at_sun.com>wrote:
>
>> Hi Tom,
>> I'm planning to make 1.9.18 release today/tomorrow, because I need this
>> and other features to be integrated to Glassfish v3 before code freeze.
>>
>> Thanks.
>>
>> WBR,
>> Alexey.
>>
>> On Aug 21, 2009, at 16:28 , Tom Magowan wrote:
>>
>> Hi Alexey,
>> So I have tested the new code, and can confirm that the issue is fixed.
>> There were plenty of POSTs with BUFFER_UNDERFLOWs, and grizzly handled them
>> all perfectly.
>>
>> Thanks for sorting this out so quickly - much appreciated!
>>
>> Please could you tell me which release will include the fix, and when is
>> it due?
>>
>> Thanks again,
>> Tom
>>
>> On Fri, Aug 21, 2009 at 12:47 PM, Tom Magowan <tom.magowan_at_googlemail.com
>> > wrote:
>>
>>> Hi Alexey,
>>> Thanks for looking at this problem!
>>>
>>> I will test the jar this afternoon, will let you know how things go by
>>> eob today (UK time)
>>>
>>> Tom
>>>
>>> On Fri, Aug 21, 2009 at 10:39 AM, Oleksiy Stashok <
>>> Oleksiy.Stashok_at_sun.com> wrote:
>>>
>>>> Hi,
>>>> I've uploaded new grizzly-framework-1.9.18-SNAPSHOT.jar, can you pls.
>>>> try it?
>>>>
>>>> Thanks.
>>>>
>>>> WBR,
>>>> Alexey.
>>>>
>>>> On Aug 21, 2009, at 10:09 , Tom Magowan wrote:
>>>>
>>>> Hi,
>>>>
>>>> I have noticed the following issue with the grizzly 1.9.18-SNAPSHOT
>>>> libs, but only in a production system; I have not been able to reproduce on
>>>> my development machine.
>>>>
>>>> During a client POST to a grizzly SSL server, a buffer underflow in the
>>>> SSLEngine leads to an EOFException. This in turn causes the http
>>>> connection to be dropped, and the client aborts the POST.
>>>>
>>>> Hopefully you can work out what is going on from the trace log below.
>>>> However, if you need more information please let me know, and I can increase
>>>> my efforts to reproduce it on my development machine (although it may be
>>>> tricky to consistently produce a TCP stream which results in such a buffer
>>>> underflow).
>>>>
>>>> Any help is appreciated!
>>>>
>>>> Kind regards,
>>>> Tom
>>>>
>>>>
>>>> [2009-08-20 16:12:10.118] ttp9999-WorkerThread(36)
>>>> grizzly.unknown D OP_READ on
>>>> sun.nio.ch.SelectionKeyImpl_at_119179d attachment:
>>>> ThreadAttachment[mode=24, threadName=null, byteBuffer=null,
>>>> timeout=1250781121666, sslEngine=2ad9ef[SSLEngine[hostname=null port=-1]
>>>> SSL_DHE_RSA_WITH_3DES_EDE_CBC_SHA],
>>>> inputBB=null,outputBB=java.nio.HeapByteBuffer[pos=0 lim=20480 cap=20480],
>>>> attributes={}]
>>>>
>>>> [2009-08-20 16:12:10.118] ttp9999-WorkerThread(36)
>>>> grizzly.unknown D Thread associated sslEngine:
>>>> 2ad9ef[SSLEngine[hostname=null port=-1] SSL_DHE_RSA_WITH_3DES_EDE_CBC_SHA]
>>>>
>>>> [2009-08-20 16:12:10.118] ttp9999-WorkerThread(36)
>>>> grizzly.unknown D SSLReadFilter. Read: 4380
>>>> Calling unwrapAll. InputBB: java.nio.HeapByteBuffer[pos=4380 lim=20480
>>>> cap=20480] byteBuffer: java.nio.HeapByteBuffer[pos=0 lim=33320 cap=33320]
>>>>
>>>> [2009-08-20 16:12:10.118] ttp9999-WorkerThread(36)
>>>> grizzly.unknown D start unwrap. engine:
>>>> ad9ef[SSLEngine[hostname=null port=-1]SSL_DHE_RSA_WITH_3DES_EDE_CBC_SHA]
>>>> buffer: java.nio.HeapByteBuffer[pos=0 lim=33320 cap=33320] secured:
>>>> java.nio.HeapByteBuffer[pos=4380 lim=20480 cap=20480]
>>>>
>>>> [2009-08-20 16:12:10.118] ttp9999-WorkerThread(36)
>>>> grizzly.unknown D
>>>> java.lang.Thread.getStackTrace(Unknown Source)
>>>> com.sun.grizzly.util.SSLUtils.unwrap(SSLUtils.java:252)
>>>> com.sun.grizzly.util.SSLUtils.unwrapAll(SSLUtils.java:193)
>>>> com.sun.grizzly.filter.SSLReadFilter.doRead(SSLReadFilter.java:288)
>>>> com.sun.grizzly.filter.SSLReadFilter.execute(SSLReadFilter.java:168)
>>>>
>>>> com.sun.grizzly.DefaultProtocolChain.executeProtocolFilter(DefaultProtocolChain.java:135)
>>>>
>>>> com.sun.grizzly.DefaultProtocolChain.execute(DefaultProtocolChain.java:102)
>>>>
>>>> com.sun.grizzly.DefaultProtocolChain.execute(DefaultProtocolChain.java:88)
>>>>
>>>> com.sun.grizzly.http.HttpProtocolChain.execute(HttpProtocolChain.java:76)
>>>>
>>>> com.sun.grizzly.ProtocolChainContextTask.doCall(ProtocolChainContextTask.java:53)
>>>>
>>>> com.sun.grizzly.SelectionKeyContextTask.call(SelectionKeyContextTask.java:57)
>>>> com.sun.grizzly.NIOContext.execute(NIOContext.java:510)
>>>>
>>>> com.sun.grizzly.SelectorHandlerRunner.handleSelectedKey(SelectorHandlerRunner.java:357)
>>>>
>>>> com.sun.grizzly.SelectorHandlerRunner.handleSelectedKeys(SelectorHandlerRunner.java:257)
>>>>
>>>> com.sun.grizzly.SelectorHandlerRunner.doSelect(SelectorHandlerRunner.java:194)
>>>>
>>>> com.sun.grizzly.SelectorHandlerRunner.run(SelectorHandlerRunner.java:129)
>>>>
>>>> com.sun.grizzly.util.FixedThreadPool$BasicWorker.dowork(FixedThreadPool.java:379)
>>>>
>>>> com.sun.grizzly.util.FixedThreadPool$BasicWorker.run(FixedThreadPool.java:360)
>>>> java.lang.Thread.run(Unknown Source)
>>>>
>>>> [2009-08-20 16:12:10.118] ttp9999-WorkerThread(36)
>>>> grizzly.unknown D after unwrap. engine:
>>>> 2ad9ef[SSLEngine[hostname=null port=-1] SSL_DHE_RSA_WITH_3DES_EDE_CBC_SHA]
>>>> buffer: java.nio.HeapByteBuffer[pos=0 lim=33320 cap=33320] secured:
>>>> java.nio.HeapByteBuffer[pos=4380 lim=20480 cap=20480] consumed: 0 produced:
>>>> 0 status: BUFFER_UNDERFLOW handshakeStatus: NOT_HANDSHAKING
>>>>
>>>> [2009-08-20 16:12:10.118] ttp9999-WorkerThread(36)
>>>> grizzly.unknown V Unblocking keep-alive exception
>>>> java.io.EOFException: Unexpected EOF read on the socket
>>>> at
>>>> com.sun.grizzly.tcp.http11.InternalInputBuffer.parseRequestLine(InternalInputBuffer.java:390)
>>>> at
>>>> com.sun.grizzly.http.ProcessorTask.parseRequest(ProcessorTask.java:782)
>>>> at
>>>> com.sun.grizzly.http.ProcessorTask.doProcess(ProcessorTask.java:654)
>>>> at
>>>> com.sun.grizzly.http.ProcessorTask.process(ProcessorTask.java:911)
>>>> at
>>>> com.sun.grizzly.http.DefaultProtocolFilter.execute(DefaultProtocolFilter.java:164)
>>>> 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.http.HttpProtocolChain.execute(HttpProtocolChain.java:76)
>>>> at
>>>> com.sun.grizzly.ProtocolChainContextTask.doCall(ProtocolChainContextTask.java:53)
>>>> at
>>>> com.sun.grizzly.SelectionKeyContextTask.call(SelectionKeyContextTask.java:57)
>>>> at com.sun.grizzly.NIOContext.execute(NIOContext.java:510)
>>>> at
>>>> com.sun.grizzly.SelectorHandlerRunner.handleSelectedKey(SelectorHandlerRunner.java:357)
>>>> at
>>>> com.sun.grizzly.SelectorHandlerRunner.handleSelectedKeys(SelectorHandlerRunner.java:257)
>>>> at
>>>> com.sun.grizzly.SelectorHandlerRunner.doSelect(SelectorHandlerRunner.java:194)
>>>> at
>>>> com.sun.grizzly.SelectorHandlerRunner.run(SelectorHandlerRunner.java:129)
>>>> 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(Unknown Source)
>>>>
>>>>
>>>>
>>>
>>
>>
>
>