users@grizzly.java.net

Re: BUFFER_UNDERFLOW problem with SSL

From: Jeanfrancois Arcand <Jeanfrancois.Arcand_at_Sun.COM>
Date: Wed, 05 Nov 2008 11:02:36 -0500

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
>