users@grizzly.java.net

Re: BUFFER_UNDERFLOW problem with SSL

From: Amy Kang <Amy.Kang_at_Sun.COM>
Date: Wed, 05 Nov 2008 13:29:11 -0800

Thanks for the information. I'v downloaded 1.9.0 and it works.

Amy

On 11/05/08 08:02, Jeanfrancois Arcand wrote:
> Good catch John! Amy, the issue with SSL and ParserProtocolFilter:
>
> https://grizzly.dev.java.net/issues/show_bug.cgi?id=255
>
> The issue has been fixed and will be included in our upcoming 1.9.0
> release (targeted Nov 17).
>
> Thanks
>
> -- Jeanfrancois
>
> John ROM wrote:
>> Hi Amy,
>> since ParserProtocolFilter extends ReadFilter you have 2 Readers in
>> your chain which does not work.
>> I would suggest that you upgrade to the latest Grizzly snapshot
>> http://download.java.net/maven/2/com/sun/grizzly/grizzly-framework/1.9.0-SNAPSHOT/
>>
>>
>> There in ParserProtocolFilter has a setSLLConfig method.
>> Then you can kick the SSLReader out of your chain.
>>
>>
>> -------- Original-Nachricht --------
>>> Datum: Wed, 05 Nov 2008 07:41:15 -0800
>>> Von: Amy Kang <Amy.Kang_at_Sun.COM>
>>> An: users_at_grizzly.dev.java.net
>>> Betreff: Re: BUFFER_UNDERFLOW problem with SSL
>>
>>> (previous log appeared truncated, here is a complete one)
>>>
>>> [ThreadID=14]: Nov 5, 2008 7:19:03 AM com.sun.grizzly.Controller
>>> doSelect
>>> FINE: OP_ACCEPT on sun.nio.ch.SelectionKeyImpl_at_a53de4
>>> [ThreadID=14]: Nov 5, 2008 7:19:03 AM com.sun.grizzly.Controller
>>> doSelect
>>> FINE: OP_READ on sun.nio.ch.SelectionKeyImpl_at_e4245
>>> [ThreadID=14]: Nov 5, 2008 7:19:03 AM com.sun.grizzly.Controller
>>> pollContext
>>> FINE: pollContext(..) Context : com.sun.grizzly.Context_at_95da38
>>> [ThreadID=15]: Nov 5, 2008 7:19:03 AM com.sun.grizzly.util.SSLUtils
>>> unwrap
>>> FINE: start unwrap. buffer: java.nio.HeapByteBuffer[pos=0 lim=16384
>>> cap=16384] secured: java.nio.HeapByteBuffer[pos=100 lim=20480
>>> cap=20480]
>>> [ThreadID=15]: Nov 5, 2008 7:19:03 AM com.sun.grizzly.util.SSLUtils
>>> unwrap
>>> FINER:
>>> java.lang.Thread.dumpThreads(Native Method)
>>> java.lang.Thread.getStackTrace(Thread.java:1383)
>>> com.sun.grizzly.util.SSLUtils.unwrap(SSLUtils.java:245)
>>> com.sun.grizzly.util.SSLUtils.doHandshake(SSLUtils.java:427)
>>> com.sun.grizzly.util.SSLUtils.doHandshake(SSLUtils.java:377)
>>> com.sun.grizzly.filter.SSLReadFilter.doHandshake(SSLReadFilter.java:223)
>>>
>>> com.sun.grizzly.filter.SSLReadFilter.execute(SSLReadFilter.java:154)
>>> com.sun.grizzly.DefaultProtocolChain.executeProtocolFilter(DefaultProtocolChain.java:136)
>>>
>>> com.sun.grizzly.DefaultProtocolChain.execute(DefaultProtocolChain.java:103)
>>>
>>> com.sun.grizzly.DefaultProtocolChain.execute(DefaultProtocolChain.java:89)
>>>
>>> com.sun.grizzly.ProtocolChainContextTask.doCall(ProtocolChainContextTask.java:67)
>>>
>>> com.sun.grizzly.SelectionKeyContextTask.call(SelectionKeyContextTask.java:56)
>>>
>>> com.sun.grizzly.util.WorkerThreadImpl.processTask(WorkerThreadImpl.java:325)
>>>
>>> com.sun.grizzly.util.WorkerThreadImpl.run(WorkerThreadImpl.java:184)
>>> [ThreadID=15]: Nov 5, 2008 7:19:03 AM com.sun.grizzly.util.SSLUtils
>>> unwrap
>>> FINE: after unwrap. buffer: java.nio.HeapByteBuffer[pos=0 lim=16384
>>> cap=16384] secured: java.nio.HeapByteBuffer[pos=0 lim=20480
>>> cap=20480] consumed:
>>> 100 produced: 0 status: OK
>>> [ThreadID=15]: Nov 5, 2008 7:19:03 AM com.sun.grizzly.util.SSLUtils
>>> unwrap
>>> FINE: start unwrap. buffer: java.nio.HeapByteBuffer[pos=0 lim=16384
>>> cap=16384] secured: java.nio.HeapByteBuffer[pos=139 lim=20480
>>> cap=20480]
>>> [ThreadID=15]: Nov 5, 2008 7:19:03 AM com.sun.grizzly.util.SSLUtils
>>> unwrap
>>> FINER:
>>> java.lang.Thread.dumpThreads(Native Method)
>>> java.lang.Thread.getStackTrace(Thread.java:1383)
>>> com.sun.grizzly.util.SSLUtils.unwrap(SSLUtils.java:245)
>>> com.sun.grizzly.util.SSLUtils.doHandshake(SSLUtils.java:427)
>>> com.sun.grizzly.util.SSLUtils.doHandshake(SSLUtils.java:377)
>>> com.sun.grizzly.filter.SSLReadFilter.doHandshake(SSLReadFilter.java:223)
>>>
>>> com.sun.grizzly.filter.SSLReadFilter.execute(SSLReadFilter.java:154)
>>> com.sun.grizzly.DefaultProtocolChain.executeProtocolFilter(DefaultProtocolChain.java:136)
>>>
>>> com.sun.grizzly.DefaultProtocolChain.execute(DefaultProtocolChain.java:103)
>>>
>>> com.sun.grizzly.DefaultProtocolChain.execute(DefaultProtocolChain.java:89)
>>>
>>> com.sun.grizzly.ProtocolChainContextTask.doCall(ProtocolChainContextTask.java:67)
>>>
>>> com.sun.grizzly.SelectionKeyContextTask.call(SelectionKeyContextTask.java:56)
>>>
>>> com.sun.grizzly.util.WorkerThreadImpl.processTask(WorkerThreadImpl.java:325)
>>>
>>> com.sun.grizzly.util.WorkerThreadImpl.run(WorkerThreadImpl.java:184)
>>> [ThreadID=15]: Nov 5, 2008 7:19:03 AM com.sun.grizzly.util.SSLUtils
>>> unwrap
>>> FINE: after unwrap. buffer: java.nio.HeapByteBuffer[pos=0 lim=16384
>>> cap=16384] secured: java.nio.HeapByteBuffer[pos=0 lim=20480
>>> cap=20480] consumed:
>>> 139 produced: 0 status: OK
>>> [ThreadID=15]: Nov 5, 2008 7:19:03 AM com.sun.grizzly.util.SSLUtils
>>> unwrap
>>> FINE: start unwrap. buffer: java.nio.HeapByteBuffer[pos=0 lim=16384
>>> cap=16384] secured: java.nio.HeapByteBuffer[pos=0 lim=20480 cap=20480]
>>> [ThreadID=15]: Nov 5, 2008 7:19:03 AM com.sun.grizzly.util.SSLUtils
>>> unwrap
>>> FINER:
>>> java.lang.Thread.dumpThreads(Native Method)
>>> java.lang.Thread.getStackTrace(Thread.java:1383)
>>> com.sun.grizzly.util.SSLUtils.unwrap(SSLUtils.java:245)
>>> com.sun.grizzly.util.SSLUtils.doHandshake(SSLUtils.java:427)
>>> com.sun.grizzly.util.SSLUtils.doHandshake(SSLUtils.java:377)
>>> com.sun.grizzly.filter.SSLReadFilter.doHandshake(SSLReadFilter.java:223)
>>>
>>> com.sun.grizzly.filter.SSLReadFilter.execute(SSLReadFilter.java:154)
>>> com.sun.grizzly.DefaultProtocolChain.executeProtocolFilter(DefaultProtocolChain.java:136)
>>>
>>> com.sun.grizzly.DefaultProtocolChain.execute(DefaultProtocolChain.java:103)
>>>
>>> com.sun.grizzly.DefaultProtocolChain.execute(DefaultProtocolChain.java:89)
>>>
>>> com.sun.grizzly.ProtocolChainContextTask.doCall(ProtocolChainContextTask.java:67)
>>>
>>> com.sun.grizzly.SelectionKeyContextTask.call(SelectionKeyContextTask.java:56)
>>>
>>> com.sun.grizzly.util.WorkerThreadImpl.processTask(WorkerThreadImpl.java:325)
>>>
>>> com.sun.grizzly.util.WorkerThreadImpl.run(WorkerThreadImpl.java:184)
>>> [ThreadID=15]: Nov 5, 2008 7:19:03 AM com.sun.grizzly.util.SSLUtils
>>> unwrap
>>> FINE: after unwrap. buffer: java.nio.HeapByteBuffer[pos=0 lim=16384
>>> cap=16384] secured: java.nio.HeapByteBuffer[pos=0 lim=20480
>>> cap=20480] consumed:
>>> 0 produced: 0 status: BUFFER_UNDERFLOW
>>> [ThreadID=15]: Nov 5, 2008 7:19:03 AM com.sun.grizzly.util.SSLUtils
>>> unwrap
>>> FINE: start unwrap. buffer: java.nio.HeapByteBuffer[pos=0 lim=16384
>>> cap=16384] secured: java.nio.HeapByteBuffer[pos=43 lim=20480 cap=20480]
>>> [ThreadID=15]: Nov 5, 2008 7:19:03 AM com.sun.grizzly.util.SSLUtils
>>> unwrap
>>> FINER:
>>> java.lang.Thread.dumpThreads(Native Method)
>>> java.lang.Thread.getStackTrace(Thread.java:1383)
>>> com.sun.grizzly.util.SSLUtils.unwrap(SSLUtils.java:245)
>>> com.sun.grizzly.util.SSLUtils.doHandshake(SSLUtils.java:427)
>>> com.sun.grizzly.util.SSLUtils.doHandshake(SSLUtils.java:377)
>>> com.sun.grizzly.filter.SSLReadFilter.doHandshake(SSLReadFilter.java:223)
>>>
>>> com.sun.grizzly.filter.SSLReadFilter.execute(SSLReadFilter.java:154)
>>> com.sun.grizzly.DefaultProtocolChain.executeProtocolFilter(DefaultProtocolChain.java:136)
>>>
>>> com.sun.grizzly.DefaultProtocolChain.execute(DefaultProtocolChain.java:103)
>>>
>>> com.sun.grizzly.DefaultProtocolChain.execute(DefaultProtocolChain.java:89)
>>>
>>> com.sun.grizzly.ProtocolChainContextTask.doCall(ProtocolChainContextTask.java:67)
>>>
>>> com.sun.grizzly.SelectionKeyContextTask.call(SelectionKeyContextTask.java:56)
>>>
>>> com.sun.grizzly.util.WorkerThreadImpl.processTask(WorkerThreadImpl.java:325)
>>>
>>> com.sun.grizzly.util.WorkerThreadImpl.run(WorkerThreadImpl.java:184)
>>> [ThreadID=15]: Nov 5, 2008 7:19:03 AM com.sun.grizzly.util.SSLUtils
>>> unwrap
>>> FINE: after unwrap. buffer: java.nio.HeapByteBuffer[pos=0 lim=16384
>>> cap=16384] secured: java.nio.HeapByteBuffer[pos=37 lim=20480
>>> cap=20480] consumed:
>>> 6 produced: 0 status: OK
>>> [ThreadID=15]: Nov 5, 2008 7:19:03 AM com.sun.grizzly.util.SSLUtils
>>> unwrap
>>> FINE: start unwrap. buffer: java.nio.HeapByteBuffer[pos=0 lim=16384
>>> cap=16384] secured: java.nio.HeapByteBuffer[pos=37 lim=20480 cap=20480]
>>> [ThreadID=15]: Nov 5, 2008 7:19:03 AM com.sun.grizzly.util.SSLUtils
>>> unwrap
>>> FINER:
>>> java.lang.Thread.dumpThreads(Native Method)
>>> java.lang.Thread.getStackTrace(Thread.java:1383)
>>> com.sun.grizzly.util.SSLUtils.unwrap(SSLUtils.java:245)
>>> com.sun.grizzly.util.SSLUtils.doHandshake(SSLUtils.java:427)
>>> com.sun.grizzly.util.SSLUtils.doHandshake(SSLUtils.java:377)
>>> com.sun.grizzly.filter.SSLReadFilter.doHandshake(SSLReadFilter.java:223)
>>>
>>> com.sun.grizzly.filter.SSLReadFilter.execute(SSLReadFilter.java:154)
>>> com.sun.grizzly.DefaultProtocolChain.executeProtocolFilter(DefaultProtocolChain.java:136)
>>>
>>> com.sun.grizzly.DefaultProtocolChain.execute(DefaultProtocolChain.java:103)
>>>
>>> com.sun.grizzly.DefaultProtocolChain.execute(DefaultProtocolChain.java:89)
>>>
>>> com.sun.grizzly.ProtocolChainContextTask.doCall(ProtocolChainContextTask.java:67)
>>>
>>> com.sun.grizzly.SelectionKeyContextTask.call(SelectionKeyContextTask.java:56)
>>>
>>> com.sun.grizzly.util.WorkerThreadImpl.processTask(WorkerThreadImpl.java:325)
>>>
>>> com.sun.grizzly.util.WorkerThreadImpl.run(WorkerThreadImpl.java:184)
>>> [ThreadID=15]: Nov 5, 2008 7:19:03 AM com.sun.grizzly.util.SSLUtils
>>> unwrap
>>> FINE: after unwrap. buffer: java.nio.HeapByteBuffer[pos=0 lim=16384
>>> cap=16384] secured: java.nio.HeapByteBuffer[pos=0 lim=20480
>>> cap=20480] consumed:
>>> 37 produced: 0 status: OK
>>> [ThreadID=15]: Nov 5, 2008 7:19:03 AM
>>> com.sun.grizzly.filter.SSLReadFilter
>>> doRead
>>> FINE: SSLReadFilter. Read: 0 Calling unwrapAll. InputBB:
>>> java.nio.HeapByteBuffer[pos=0 lim=20480 cap=20480] byteBuffer:
>>> java.nio.HeapByteBuffer[pos=0
>>> lim=16384 cap=16384]
>>> [ThreadID=15]: Nov 5, 2008 7:19:03 AM com.sun.grizzly.util.SSLUtils
>>> unwrap
>>> FINE: start unwrap. buffer: java.nio.HeapByteBuffer[pos=0 lim=16384
>>> cap=16384] secured: java.nio.HeapByteBuffer[pos=0 lim=20480 cap=20480]
>>> [ThreadID=15]: Nov 5, 2008 7:19:03 AM com.sun.grizzly.util.SSLUtils
>>> unwrap
>>> FINER:
>>> java.lang.Thread.dumpThreads(Native Method)
>>> java.lang.Thread.getStackTrace(Thread.java:1383)
>>> com.sun.grizzly.util.SSLUtils.unwrap(SSLUtils.java:245)
>>> com.sun.grizzly.util.SSLUtils.unwrapAll(SSLUtils.java:192)
>>> com.sun.grizzly.filter.SSLReadFilter.doRead(SSLReadFilter.java:268)
>>> com.sun.grizzly.filter.SSLReadFilter.doHandshake(SSLReadFilter.java:226)
>>>
>>> com.sun.grizzly.filter.SSLReadFilter.execute(SSLReadFilter.java:154)
>>> com.sun.grizzly.DefaultProtocolChain.executeProtocolFilter(DefaultProtocolChain.java:136)
>>>
>>> com.sun.grizzly.DefaultProtocolChain.execute(DefaultProtocolChain.java:103)
>>>
>>> com.sun.grizzly.DefaultProtocolChain.execute(DefaultProtocolChain.java:89)
>>>
>>> com.sun.grizzly.ProtocolChainContextTask.doCall(ProtocolChainContextTask.java:67)
>>>
>>> com.sun.grizzly.SelectionKeyContextTask.call(SelectionKeyContextTask.java:56)
>>>
>>> com.sun.grizzly.util.WorkerThreadImpl.processTask(WorkerThreadImpl.java:325)
>>>
>>> com.sun.grizzly.util.WorkerThreadImpl.run(WorkerThreadImpl.java:184)
>>> [ThreadID=15]: Nov 5, 2008 7:19:03 AM com.sun.grizzly.util.SSLUtils
>>> unwrap
>>> FINE: after unwrap. buffer: java.nio.HeapByteBuffer[pos=0 lim=16384
>>> cap=16384] secured: java.nio.HeapByteBuffer[pos=0 lim=20480
>>> cap=20480] consumed:
>>> 0 produced: 0 status: BUFFER_UNDERFLOW
>>> [ThreadID=15]: Nov 5, 2008 7:19:03 AM
>>> com.sun.messaging.bridge.service.sp.SPProtocolParser
>>> isExpectingMoreData
>>> FINEST: expectingMoreData=true
>>> [ThreadID=15]: Nov 5, 2008 7:19:03 AM
>>> com.sun.messaging.bridge.service.sp.SPProtocolParser startBuffer
>>> FINEST:
>>> this:com.sun.messaging.bridge.service.sp.SPProtocolParser_at_190ef12
>>> [ThreadID=15]: Nov 5, 2008 7:19:03 AM
>>> com.sun.messaging.bridge.service.sp.SPProtocolParser hasNextMessage
>>> FINEST: this:
>>> com.sun.messaging.bridge.service.sp.SPProtocolParser_at_190ef12
>>> [ThreadID=15]: Nov 5, 2008 7:19:03 AM
>>> com.sun.messaging.bridge.service.sp.SPProtocolParser hasNextMessage
>>> FINEST: _position:_buf.position[0:58]
>>> [ThreadID=15]: Nov 5, 2008 7:19:03 AM
>>> com.sun.messaging.bridge.service.sp.SPProtocolParser hasNextMessage
>>> ?B?X?T????|ffer=5?�??T?ETNu?-????T?"????@???<?
>>> [ThreadID=15]: Nov 5, 2008 7:19:03 AM
>>> com.sun.messaging.bridge.service.sp.SPFrameMessage parseCommand
>>> FINEST: parseCommand: start:end[0:58]
>>> [ThreadID=15]: Nov 5, 2008 7:19:03 AM
>>> com.sun.messaging.bridge.service.sp.SPFrameMessage parseCommand
>>> FINEST: parseCommand: start[0] command line not found
>>> [ThreadID=15]: Nov 5, 2008 7:19:03 AM
>>> com.sun.messaging.bridge.service.sp.SPProtocolParser hasNextMessage
>>> FINEST: returned from parseCommand
>>> [ThreadID=15]: Nov 5, 2008 7:19:03 AM
>>> com.sun.messaging.bridge.service.sp.SPProtocolParser
>>> hasMoreBytesToParse
>>> FINEST: hasMoreBytesToParse=false
>>> [ThreadID=15]: Nov 5, 2008 7:19:03 AM
>>> com.sun.messaging.bridge.service.sp.SPProtocolParser
>>> isExpectingMoreData
>>> FINEST: expectingMoreData=true
>>> [ThreadID=15]: Nov 5, 2008 7:19:03 AM
>>> com.sun.messaging.bridge.service.sp.SPProtocolParser releaseBuffer
>>> FINEST: [expectingMoreData=true, hasMoreBytesToParse=false]
>>> [ThreadID=15]: Nov 5, 2008 7:19:03 AM com.sun.grizzly.Controller
>>> returnContext
>>> FINE: returnContext() Context : com.sun.grizzly.Context_at_95da38
>>>
>>>
>>> ----- Original Message -----
>>> From: Amy Kang <Amy.Kang_at_Sun.COM>
>>> Date: Wednesday, November 5, 2008 7:31 am
>>> Subject: Re: BUFFER_UNDERFLOW problem with SSL
>>> To: users_at_grizzly.dev.java.net
>>>
>>>
>>>> Please see below for more debug logging output.
>>>> This time I'v used stateful protocol chain. My parser
>>>> did get called but with garbage as if it's not unwrapped.
>>>>
>>>> My parser extends com.sun.grizzly.ParserProtocolFilter
>>>> by overriding newProtocolParser() method.
>>>>
>>>> -------------------------------------------------------------------
>>>> Nov 5, 2008 7:19:03 AM com.sun.grizzly.Controller doSelect
>>>> FINE: OP_ACCEPT on sun.nio.ch.SelectionKeyImpl_at_a53de4
>>>> Nov 5, 2008 7:19:03 AM com.sun.grizzly.Controller doSelect
>>>> FINE: OP_READ on sun.nio.ch.SelectionKeyImpl_at_e4245
>>>> Nov 5, 2008 7:19:03 AM com.sun.grizzly.Controller pollContext
>>>> FINE: pollContext(..) Context : com.sun.grizzly.Context_at_95da38
>>>> Nov 5, 2008 7:19:03 AM com.sun.grizzly.util.SSLUtils unwrap
>>>> FINE: start unwrap. buffer: java.nio.HeapByteBuffer[pos=0 lim=16384
>>>> cap=16384] secured: java.nio.HeapByteBuffer[pos=100 lim=20480
>>>> cap=20480]
>>>> Nov 5, 2008 7:19:03 AM com.sun.grizzly.util.SSLUtils unwrap
>>>> FINER:
>>>> java.lang.Thread.dumpThreads(Native Method)
>>>> java.lang.Thread.getStackTrace(Thread.java:1383)
>>>> com.sun.grizzly.util.SSLUtils.unwrap(SSLUtils.java:245)
>>>> com.sun.grizzly.util.SSLUtils.doHandshake(SSLUtils.java:427)
>>>> com.sun.grizzly.util.SSLUtils.doHandshake(SSLUtils.java:377)
>>>> com.sun.grizzly.filter.SSLReadFilter.doHandshake(SSLReadFilter.java:223)
>>>>
>>>> com.sun.grizzly.filter.SSLReadFilter.execute(SSLReadFilter.java:154)
>>>>
>>> com.sun.grizzly.DefaultProtocolChain.executeProtocolFilter(DefaultProtocolChain.java:136)
>>>
>>> com.sun.grizzly.DefaultProtocolChain.execute(DefaultProtocolChain.java:103)
>>>
>>> com.sun.grizzly.DefaultProtocolChain.execute(DefaultProtocolChain.java:89)
>>>
>>> com.sun.grizzly.ProtocolChainContextTask.doCall(ProtocolChainContextTask.java:67)
>>>
>>> com.sun.grizzly.SelectionKeyContextTask.call(SelectionKeyContextTask.java:56)
>>>
>>> com.sun.grizzly.util.WorkerThreadImpl.processTask(WorkerThreadImpl.java:325)
>>>
>>>> com.sun.grizzly.util.WorkerThreadImpl.run(WorkerThreadImpl.java:184)
>>>> Nov 5, 2008 7:19:03 AM com.sun.grizzly.util.SSLUtils unwrap
>>>> FINE: after unwrap. buffer: java.nio.HeapByteBuffer[pos=0 lim=16384
>>>> cap=16384] secured: java.nio.HeapByteBuffer[pos=0 lim=20480
>>>> cap=20480] consumed: 100 produced: 0 status: OK
>>>> Nov 5, 2008 7:19:03 AM com.sun.grizzly.util.SSLUtils unwrap
>>>> FINE: start unwrap. buffer: java.nio.HeapByteBuffer[pos=0 lim=16384
>>>> cap=16384] secured: java.nio.HeapByteBuffer[pos=139 lim=20480
>>>> cap=20480]
>>>> Nov 5, 2008 7:19:03 AM com.sun.grizzly.util.SSLUtils unwrap
>>>> FINER:
>>>> java.lang.Thread.dumpThreads(Native Method)
>>>> java.lang.Thread.getStackTrace(Thread.java:1383)
>>>> com.sun.grizzly.util.SSLUtils.unwrap(SSLUtils.java:245)
>>>> com.sun.grizzly.util.SSLUtils.doHandshake(SSLUtils.java:427)
>>>> com.sun.grizzly.util.SSLUtils.doHandshake(SSLUtils.java:377)
>>>> com.sun.grizzly.filter.SSLReadFilter.doHandshake(SSLReadFilter.java:223)
>>>>
>>>> com.sun.grizzly.filter.SSLReadFilter.execute(SSLReadFilter.java:154)
>>>>
>>> com.sun.grizzly.DefaultProtocolChain.executeProtocolFilter(DefaultProtocolChain.java:136)
>>>
>>> com.sun.grizzly.DefaultProtocolChain.execute(DefaultProtocolChain.java:103)
>>>
>>> com.sun.grizzly.DefaultProtocolChain.execute(DefaultProtocolChain.java:89)
>>>
>>> com.sun.grizzly.ProtocolChainContextTask.doCall(ProtocolChainContextTask.java:67)
>>>
>>> com.sun.grizzly.SelectionKeyContextTask.call(SelectionKeyContextTask.java:56)
>>>
>>> com.sun.grizzly.util.WorkerThreadImpl.processTask(WorkerThreadImpl.java:325)
>>>
>>>> com.sun.grizzly.util.WorkerThreadImpl.run(WorkerThreadImpl.java:184)
>>>> Nov 5, 2008 7:19:03 AM com.sun.grizzly.util.SSLUtils unwrap
>>>> FINE: after unwrap. buffer: java.nio.HeapByteBuffer[pos=0 lim=16384
>>>> cap=16384] secured: java.nio.HeapByteBuffer[pos=0 lim=20480
>>>> cap=20480] consumed: 139 produced: 0 status: OK
>>>> Nov 5, 2008 7:19:03 AM com.sun.grizzly.util.SSLUtils unwrap
>>>> :q
>>>> yueyang >cat g
>>>> Nov 5, 2008 7:19:03 AM com.sun.grizzly.Controller doSelect
>>>> FINE: OP_ACCEPT on sun.nio.ch.SelectionKeyImpl_at_a53de4
>>>> Nov 5, 2008 7:19:03 AM com.sun.grizzly.Controller doSelect
>>>> FINE: OP_READ on sun.nio.ch.SelectionKeyImpl_at_e4245
>>>> Nov 5, 2008 7:19:03 AM com.sun.grizzly.Controller pollContext
>>>> FINE: pollContext(..) Context : com.sun.grizzly.Context_at_95da38
>>>> Nov 5, 2008 7:19:03 AM com.sun.grizzly.util.SSLUtils unwrap
>>>> FINE: start unwrap. buffer: java.nio.HeapByteBuffer[pos=0 lim=16384
>>>> cap=16384] secured: java.nio.HeapByteBuffer[pos=100 lim=20480
>>>> cap=20480]
>>>> Nov 5, 2008 7:19:03 AM com.sun.grizzly.util.SSLUtils unwrap
>>>> FINER:
>>>> java.lang.Thread.dumpThreads(Native Method)
>>>> java.lang.Thread.getStackTrace(Thread.java:1383)
>>>> com.sun.grizzly.util.SSLUtils.unwrap(SSLUtils.java:245)
>>>> com.sun.grizzly.util.SSLUtils.doHandshake(SSLUtils.java:427)
>>>> com.sun.grizzly.util.SSLUtils.doHandshake(SSLUtils.java:377)
>>>> com.sun.grizzly.filter.SSLReadFilter.doHandshake(SSLReadFilter.java:223)
>>>>
>>>> com.sun.grizzly.filter.SSLReadFilter.execute(SSLReadFilter.java:154)
>>>>
>>> com.sun.grizzly.DefaultProtocolChain.executeProtocolFilter(DefaultProtocolChain.java:136)
>>>
>>> com.sun.grizzly.DefaultProtocolChain.execute(DefaultProtocolChain.java:103)
>>>
>>> com.sun.grizzly.DefaultProtocolChain.execute(DefaultProtocolChain.java:89)
>>>
>>> com.sun.grizzly.ProtocolChainContextTask.doCall(ProtocolChainContextTask.java:67)
>>>
>>> com.sun.grizzly.SelectionKeyContextTask.call(SelectionKeyContextTask.java:56)
>>>
>>> com.sun.grizzly.util.WorkerThreadImpl.processTask(WorkerThreadImpl.java:325)
>>>
>>>> com.sun.grizzly.util.WorkerThreadImpl.run(WorkerThreadImpl.java:184)
>>>> Nov 5, 2008 7:19:03 AM com.sun.grizzly.util.SSLUtils unwrap
>>>> FINE: after unwrap. buffer: java.nio.HeapByteBuffer[pos=0 lim=16384
>>>> cap=16384] secured: java.nio.HeapByteBuffer[pos=0 lim=20480
>>>> cap=20480] consumed: 100 produced: 0 status: OK
>>>> Nov 5, 2008 7:19:03 AM com.sun.grizzly.util.SSLUtils unwrap
>>>> FINE: start unwrap. buffer: java.nio.HeapByteBuffer[pos=0 lim=16384
>>>> cap=16384] secured: java.nio.HeapByteBuffer[pos=139 lim=20480
>>>> cap=20480]
>>>> Nov 5, 2008 7:19:03 AM com.sun.grizzly.util.SSLUtils unwrap
>>>> FINER:
>>>> java.lang.Thread.dumpThreads(Native Method)
>>>> java.lang.Thread.getStackTrace(Thread.java:1383)
>>>> com.sun.grizzly.util.SSLUtils.unwrap(SSLUtils.java:245)
>>>> com.sun.grizzly.util.SSLUtils.doHandshake(SSLUtils.java:427)
>>>> com.sun.grizzly.util.SSLUtils.doHandshake(SSLUtils.java:377)
>>>> com.sun.grizzly.filter.SSLReadFilter.doHandshake(SSLReadFilter.java:223)
>>>>
>>>> com.sun.grizzly.filter.SSLReadFilter.execute(SSLReadFilter.java:154)
>>>>
>>> com.sun.grizzly.DefaultProtocolChain.executeProtocolFilter(DefaultProtocolChain.java:136)
>>>
>>> com.sun.grizzly.DefaultProtocolChain.execute(DefaultProtocolChain.java:103)
>>>
>>> com.sun.grizzly.DefaultProtocolChain.execute(DefaultProtocolChain.java:89)
>>>
>>> com.sun.grizzly.ProtocolChainContextTask.doCall(ProtocolChainContextTask.java:67)
>>>
>>> com.sun.grizzly.SelectionKeyContextTask.call(SelectionKeyContextTask.java:56)
>>>
>>> com.sun.grizzly.util.WorkerThreadImpl.processTask(WorkerThreadImpl.java:325)
>>>
>>>> com.sun.grizzly.util.WorkerThreadImpl.run(WorkerThreadImpl.java:184)
>>>> Nov 5, 2008 7:19:03 AM com.sun.grizzly.util.SSLUtils unwrap
>>>> FINE: after unwrap. buffer: java.nio.HeapByteBuffer[pos=0 lim=16384
>>>> cap=16384] secured: java.nio.HeapByteBuffer[pos=0 lim=20480
>>>> cap=20480] consumed: 139 produced: 0 status: OK
>>>> Nov 5, 2008 7:19:03 AM com.sun.grizzly.util.SSLUtils unwrap
>>>> FINE: start unwrap. buffer: java.nio.HeapByteBuffer[pos=0 lim=16384
>>>> cap=16384] secured: java.nio.HeapByteBuffer[pos=0 lim=20480 cap=20480]
>>>> Nov 5, 2008 7:19:03 AM com.sun.grizzly.util.SSLUtils unwrap
>>>> FINER:
>>>> java.lang.Thread.dumpThreads(Native Method)
>>>> java.lang.Thread.getStackTrace(Thread.java:1383)
>>>> com.sun.grizzly.util.SSLUtils.unwrap(SSLUtils.java:245)
>>>> com.sun.grizzly.util.SSLUtils.doHandshake(SSLUtils.java:427)
>>>> com.sun.grizzly.util.SSLUtils.doHandshake(SSLUtils.java:377)
>>>> com.sun.grizzly.filter.SSLReadFilter.doHandshake(SSLReadFilter.java:223)
>>>>
>>>> com.sun.grizzly.filter.SSLReadFilter.execute(SSLReadFilter.java:154)
>>>>
>>> com.sun.grizzly.DefaultProtocolChain.executeProtocolFilter(DefaultProtocolChain.java:136)
>>>
>>> com.sun.grizzly.DefaultProtocolChain.execute(DefaultProtocolChain.java:103)
>>>
>>> com.sun.grizzly.DefaultProtocolChain.execute(DefaultProtocolChain.java:89)
>>>
>>> com.sun.grizzly.ProtocolChainContextTask.doCall(ProtocolChainContextTask.java:67)
>>>
>>> com.sun.grizzly.SelectionKeyContextTask.call(SelectionKeyContextTask.java:56)
>>>
>>> com.sun.grizzly.util.WorkerThreadImpl.processTask(WorkerThreadImpl.java:325)
>>>
>>>> com.sun.grizzly.util.WorkerThreadImpl.run(WorkerThreadImpl.java:184)
>>>> Nov 5, 2008 7:19:03 AM com.sun.grizzly.util.SSLUtils unwrap
>>>> FINE: after unwrap. buffer: java.nio.HeapByteBuffer[pos=0 lim=16384
>>>> cap=16384] secured: java.nio.HeapByteBuffer[pos=0 lim=20480
>>>> cap=20480] consumed: 0 produced: 0 status: BUFFER_UNDERFLOW
>>>> Nov 5, 2008 7:19:03 AM com.sun.grizzly.util.SSLUtils unwrap
>>>> FINE: start unwrap. buffer: java.nio.HeapByteBuffer[pos=0 lim=16384
>>>> cap=16384] secured: java.nio.HeapByteBuffer[pos=43 lim=20480
>>>> cap=20480]
>>>> Nov 5, 2008 7:19:03 AM com.sun.grizzly.util.SSLUtils unwrap
>>>> FINER:
>>>> java.lang.Thread.dumpThreads(Native Method)
>>>> java.lang.Thread.getStackTrace(Thread.java:1383)
>>>> com.sun.grizzly.util.SSLUtils.unwrap(SSLUtils.java:245)
>>>> com.sun.grizzly.util.SSLUtils.doHandshake(SSLUtils.java:427)
>>>> com.sun.grizzly.util.SSLUtils.doHandshake(SSLUtils.java:377)
>>>> com.sun.grizzly.filter.SSLReadFilter.doHandshake(SSLReadFilter.java:223)
>>>>
>>>> com.sun.grizzly.filter.SSLReadFilter.execute(SSLReadFilter.java:154)
>>>>
>>> com.sun.grizzly.DefaultProtocolChain.executeProtocolFilter(DefaultProtocolChain.java:136)
>>>
>>> com.sun.grizzly.DefaultProtocolChain.execute(DefaultProtocolChain.java:103)
>>>
>>> com.sun.grizzly.DefaultProtocolChain.execute(DefaultProtocolChain.java:89)
>>>
>>> com.sun.grizzly.ProtocolChainContextTask.doCall(ProtocolChainContextTask.java:67)
>>>
>>> com.sun.grizzly.SelectionKeyContextTask.call(SelectionKeyContextTask.java:56)
>>>
>>> com.sun.grizzly.util.WorkerThreadImpl.processTask(WorkerThreadImpl.java:325)
>>>
>>>> com.sun.grizzly.util.WorkerThreadImpl.run(WorkerThreadImpl.java:184)
>>>> Nov 5, 2008 7:19:03 AM com.sun.grizzly.util.SSLUtils unwrap
>>>> FINE: after unwrap. buffer: java.nio.HeapByteBuffer[pos=0 lim=16384
>>>> cap=16384] secured: java.nio.HeapByteBuffer[pos=37 lim=20480
>>>> cap=20480] consumed: 6 produced: 0 status: OK
>>>> Nov 5, 2008 7:19:03 AM com.sun.grizzly.util.SSLUtils unwrap
>>>> FINE: start unwrap. buffer: java.nio.HeapByteBuffer[pos=0 lim=16384
>>>> cap=16384] secured: java.nio.HeapByteBuffer[pos=37 lim=20480
>>>> cap=20480]
>>>> Nov 5, 2008 7:19:03 AM com.sun.grizzly.util.SSLUtils unwrap
>>>> FINER:
>>>> java.lang.Thread.dumpThreads(Native Method)
>>>> java.lang.Thread.getStackTrace(Thread.java:1383)
>>>> com.sun.grizzly.util.SSLUtils.unwrap(SSLUtils.java:245)
>>>> com.sun.grizzly.util.SSLUtils.doHandshake(SSLUtils.java:427)
>>>> com.sun.grizzly.util.SSLUtils.doHandshake(SSLUtils.java:377)
>>>> com.sun.grizzly.filter.SSLReadFilter.doHandshake(SSLReadFilter.java:223)
>>>>
>>>> com.sun.grizzly.filter.SSLReadFilter.execute(SSLReadFilter.java:154)
>>>>
>>> com.sun.grizzly.DefaultProtocolChain.executeProtocolFilter(DefaultProtocolChain.java:136)
>>>
>>> com.sun.grizzly.DefaultProtocolChain.execute(DefaultProtocolChain.java:103)
>>>
>>> com.sun.grizzly.DefaultProtocolChain.execute(DefaultProtocolChain.java:89)
>>>
>>> com.sun.grizzly.ProtocolChainContextTask.doCall(ProtocolChainContextTask.java:67)
>>>
>>> com.sun.grizzly.SelectionKeyContextTask.call(SelectionKeyContextTask.java:56)
>>>
>>> com.sun.grizzly.util.WorkerThreadImpl.processTask(WorkerThreadImpl.java:325)
>>>
>>>> com.sun.grizzly.util.WorkerThreadImpl.run(WorkerThreadImpl.java:184)
>>>> Nov 5, 2008 7:19:03 AM com.sun.grizzly.util.SSLUtils unwrap
>>>> FINE: after unwrap. buffer: java.nio.HeapByteBuffer[pos=0 lim=16384
>>>> cap=16384] secured: java.nio.HeapByteBuffer[pos=0 lim=20480
>>>> cap=20480] consumed: 37 produced: 0 status: OK
>>>> Nov 5, 2008 7:19:03 AM com.sun.grizzly.filter.SSLReadFilter doRead
>>>> FINE: SSLReadFilter. Read: 0 Calling unwrapAll. InputBB:
>>>> java.nio.HeapByteBuffer[pos=0 lim=20480 cap=20480] byteBuffer:
>>>> java.nio.HeapByteBuffer[pos=0 lim=16384 cap=16384]
>>>> Nov 5, 2008 7:19:03 AM com.sun.grizzly.util.SSLUtils unwrap
>>>> FINE: start unwrap. buffer: java.nio.HeapByteBuffer[pos=0 lim=16384
>>>> cap=16384] secured: java.nio.HeapByteBuffer[pos=0 lim=20480 cap=20480]
>>>> Nov 5, 2008 7:19:03 AM com.sun.grizzly.util.SSLUtils unwrap
>>>> FINER:
>>>> java.lang.Thread.dumpThreads(Native Method)
>>>> java.lang.Thread.getStackTrace(Thread.java:1383)
>>>> com.sun.grizzly.util.SSLUtils.unwrap(SSLUtils.java:245)
>>>> com.sun.grizzly.util.SSLUtils.unwrapAll(SSLUtils.java:192)
>>>> com.sun.grizzly.filter.SSLReadFilter.doRead(SSLReadFilter.java:268)
>>>> com.sun.grizzly.filter.SSLReadFilter.doHandshake(SSLReadFilter.java:226)
>>>>
>>>> com.sun.grizzly.filter.SSLReadFilter.execute(SSLReadFilter.java:154)
>>>>
>>> com.sun.grizzly.DefaultProtocolChain.executeProtocolFilter(DefaultProtocolChain.java:136)
>>>
>>> com.sun.grizzly.DefaultProtocolChain.execute(DefaultProtocolChain.java:103)
>>>
>>> com.sun.grizzly.DefaultProtocolChain.execute(DefaultProtocolChain.java:89)
>>>
>>> com.sun.grizzly.ProtocolChainContextTask.doCall(ProtocolChainContextTask.java:67)
>>>
>>> com.sun.grizzly.SelectionKeyContextTask.call(SelectionKeyContextTask.java:56)
>>>
>>> com.sun.grizzly.util.WorkerThreadImpl.processTask(WorkerThreadImpl.java:pectingMoreData
>>>
>>>> FINEST: expectingMoreData=true
>>>> Nov 5, 2008 7:19:03 AM
>>>> com.sun.messaging.bridge.service.Custom.CustomProtocolParser
>>> releaseBuffer
>>>> FINEST: [expectingMoreData=true, hasMoreBytesToParse=false]
>>>> Nov 5, 2008 7:19:03 AM com.sun.grizzly.Controller returnContext
>>>> FINE: returnContext() Context : com.sun.grizzly.Context_at_95da38
>>>>
>>>> ----- Original Message -----
>>>> From: Oleksiy Stashok <Oleksiy.Stashok_at_Sun.COM>
>>>> Date: Wednesday, November 5, 2008 1:35 am
>>>> Subject: Re: BUFFER_UNDERFLOW problem with SSL
>>>> To: users_at_grizzly.dev.java.net
>>>>
>>>>
>>>>> Agree with John. Please set FINEST or ALL logging level.
>>>>> For me it looks like handshake phase passed fine, but then
>>>>> nothing happens... nothing comes to server.
>>>>>
>>>>> Thanks.
>>>>>
>>>>> WBR,
>>>>> Alexey.
>>>>>
>>>>> On Nov 5, 2008, at 7:37 , John ROM wrote:
>>>>>
>>>>>> Hi Amy,
>>>>>> could you set log level to ALL?
>>>>>> just to make sure, your Filter is not using
>>>>>> com.sun.grizzly.filter.ParserProtocolFilter but you have written a
>>>>
>>>>>> custom ProtocolFilter?
>>>>>>
>>>>>> could you share your code?
>>>>>>
>>>>>> Many Greetings
>>>>>> John
>>>>>>
>>>>>> -------- Original-Nachricht --------
>>>>>>> Datum: Tue, 04 Nov 2008 17:45:55 -0800
>>>>>>> Von: Amy Kang <Amy.Kang_at_Sun.COM>
>>>>>>> An: users_at_grizzly.dev.java.net
>>>>>>> Betreff: BUFFER_UNDERFLOW problem with SSL
>>>>>>> Hi,
>>>>>>>
>>>>>>> Have anyone seen similar problem using SSL ? My server uses
>>>>>>> SSLReadFilter at front of my own protocol parser and filter.
>>> However
>>>>>>> my parser and filter were not get called and the client does not
>>>> get
>>>>>>> a reply after sent its first application data packet. I'm using
>>>>>>> self-signed
>>>>>>> certificate on server side and client uses a trust all default
>>>>>>> TrustManager,
>>>>>>> Grizzly 1.8.6.3
>>>>>>>
>>>>>>> Nov 4, 2008 2:57:43 AM com.sun.grizzly.Controller doSelect
>>>>>>> FINE: OP_ACCEPT on sun.nio.ch.SelectionKeyImpl_at_716cb7
>>>>>>> Nov 4, 2008 2:57:43 AM com.sun.grizzly.Controller doSelect
>>>>>>> FINE: OP_READ on sun.nio.ch.SelectionKeyImpl_at_1a61172
>>>>>>> Nov 4, 2008 2:57:43 AM com.sun.grizzly.Controller pollContext
>>>>>>> FINE: pollContext(..) Context : com.sun.grizzly.Context_at_6ed322
>>>>>>> Nov 4, 2008 2:57:45 AM com.sun.grizzly.util.SSLUtils unwrap
>>>>>>> FINE: start unwrap. buffer: java.nio.HeapByteBuffer[pos=0 lim=16384
>>>>>>> cap=16384] secured: java.nio.HeapByteBuffer[pos=100 lim=20480
>>>>>>> cap=20480]
>>>>>>> Nov 4, 2008 2:57:45 AM com.sun.grizzly.util.SSLUtils unwrap
>>>>>>> FINE: after unwrap. buffer: java.nio.HeapByteBuffer[pos=0 lim=16384
>>>>>>> cap=16384] secured: java.nio.HeapByteBuffer[pos=0 lim=20480
>>>>>>> cap=20480]
>>>>>>> consumed: 100 produced: 0 status: OK
>>>>>>> Nov 4, 2008 2:57:45 AM com.sun.grizzly.util.SSLUtils unwrap
>>>>>>> FINE: start unwrap. buffer: java.nio.HeapByteBuffer[pos=0 lim=16384
>>>>>>> cap=16384] secured: java.nio.HeapByteBuffer[pos=139 lim=20480
>>>>>>> cap=20480]
>>>>>>> Nov 4, 2008 2:57:45 AM com.sun.grizzly.util.SSLUtils unwrap
>>>>>>> FINE: after unwrap. buffer: java.nio.HeapByteBuffer[pos=0 lim=16384
>>>>>>> cap=16384] secured: java.nio.HeapByteBuffer[pos=0 lim=20480
>>>>>>> cap=20480]
>>>>>>> consumed: 139 produced: 0 status: OK
>>>>>>> Nov 4, 2008 2:57:45 AM com.sun.grizzly.util.SSLUtils unwrap
>>>>>>> FINE: start unwrap. buffer: java.nio.HeapByteBuffer[pos=0 lim=16384
>>>>>>> cap=16384] secured: java.nio.HeapByteBuffer[pos=0 lim=20480
>>>>>>> cap=20480]
>>>>>>> Nov 4, 2008 2:57:45 AM com.sun.grizzly.util.SSLUtils unwrap
>>>>>>> FINE: after unwrap. buffer: java.nio.HeapByteBuffer[pos=0 lim=16384
>>>>>>> cap=16384] secured: java.nio.HeapByteBuffer[pos=0 lim=20480
>>>>>>> cap=20480]
>>>>>>> consumed: 0 p roduced: 0 status: BUFFER_UNDERFLOW
>>>>>>> Nov 4, 2008 2:57:45 AM com.sun.grizzly.util.SSLUtils unwrap
>>>>>>> .....
>>>>>>>
>>>>>>> Thanks,
>>>>>>> Amy
>>>>>>>
>>>>>>>
>>> ---------------------------------------------------------------------
>>>>>>> To unsubscribe, e-mail: users-unsubscribe_at_grizzly.dev.java.net
>>>>>>> For additional commands, e-mail: users-help_at_grizzly.dev.java.net
>>>>>> --
>>>>>> "Feel free" - 10 GB Mailbox, 100 FreeSMS/Monat ...
>>>>>> Jetzt GMX TopMail testen: http://www.gmx.net/de/go/topmail
>>>>>>
>>>>>>
>>> ---------------------------------------------------------------------
>>>>>> 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
>>>>>
>>>> ---------------------------------------------------------------------
>>>> 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
>>
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: users-unsubscribe_at_grizzly.dev.java.net
> For additional commands, e-mail: users-help_at_grizzly.dev.java.net
>