users@grizzly.java.net

Re: FW: Grizzly SSL Connection Closed Error

From: Oleksiy Stashok <oleksiy.stashok_at_oracle.com>
Date: Mon, 12 Sep 2011 12:01:23 +0200

Looks like Grizzly expects initial handshake data from a client, but
never gets it.
What are you using as a client? What are the SSL settings used for
client side config?

WBR,
Alexey.

On 09/10/2011 12:19 AM, Bessette-Halsema, Dominique E wrote:
>
> To be clearer I did all the gets, is it acceptable that the ByteBuffer
> in the SSLUtils class is 0?
>
> 15:16:48,732 FINE [GRIZZLY] inputBB getChar
>
> 15:16:48,732 DEBUG [GRIZZLY] inputBB getChar
>
> 15:16:48,732 FINE [GRIZZLY] inputBB get0
>
> 15:16:48,732 DEBUG [GRIZZLY] inputBB get0
>
> 15:16:48,732 FINE [GRIZZLY] inputBB getDouble0.0
>
> 15:16:48,732 DEBUG [GRIZZLY] inputBB getDouble0.0
>
> 15:16:48,732 FINE [GRIZZLY] inputBB getFloat0.0
>
> 15:16:48,732 DEBUG [GRIZZLY] inputBB getFloat0.0
>
> 15:16:48,732 FINE [GRIZZLY] inputBB getInt0
>
> 15:16:48,747 DEBUG [GRIZZLY] inputBB getInt0
>
> 15:16:48,747 FINE [GRIZZLY] inputBB getLong0
>
> 15:16:48,747 DEBUG [GRIZZLY] inputBB getLong0
>
> 15:16:48,747 FINE [GRIZZLY] inputBB getShort0
>
> 15:16:48,747 DEBUG [GRIZZLY] inputBB getShort0
>
> *From:*Bessette-Halsema, Dominique E
> *Sent:* Friday, September 09, 2011 3:02 PM
> *To:* users_at_grizzly.java.net
> *Subject:* FW: Grizzly SSL Connection Closed Error
>
> Also in my debugging of the SSLUtils class I checked the ByteBuffer
> inputBB variable and it returns nothing. Any ideas?
>
> *public**static**int*doRead(SelectionKey key, ByteBufferinputBB,
>
> SSLEngine sslEngine, *int*timeout){
>
> *if*(key == *null*) *return*-1;
>
> Logger logg = SSLSelectorThread./logger/();
>
> SSLEngineResult _result_ = *null*;
>
> *int*count = 1;
>
> *int*byteRead = 0;
>
> *int*preReadInputBBPos = inputBB.position();
>
> logg.log(Level./FINE/,"preReadInputBBPos "+preReadInputBBPos);
>
> Selector readSelector = *null*;
>
> SelectionKey tmpKey = *null*;
>
> *try*{
>
> SocketChannel socketChannel = (SocketChannel)key.channel();
>
> logg.log(Level./FINE/,"inputBB getChar"+inputBB.getChar()); //this
> returns nothing
>
> ...............
>
> .................
>
> .................
>
> From the server.log
>
> 2011-09-09 14:57:16,704 DEBUG [GRIZZLY] inputBB getChar
>
> *From:*Bessette-Halsema, Dominique E
> *Sent:* Wednesday, September 07, 2011 2:15 PM
> *To:* users_at_grizzly.java.net
> *Subject:* RE: Grizzly SSL Connection Closed Error
>
> After further investigation it seems that the error is in the SSLUtils
> class. Does anyone have any insight please? Thank You in advanced.
>
> In the doHandshake method:
>
> eof =0
>
> handshakeStatus = NEED_UNWRAP
>
> the NEED_UNWRAP case calls
>
> *if*(/doRead/(key,inputBB,sslEngine, timeout) <= eof)
>
> in the doRead method:
>
> timeout=30000
>
> on line 145 in the doRead method :
>
> *if*(timeout > 0) {
>
> code= readSelector.select(timeout);
>
> } *else*{
>
> code= readSelector.selectNow();
>
> }
>
> logg.log(Level./FINE/,"code is "+code);
>
> Now the code from readSelector.select(timeout) = 0
>
> On line 155 it states:
>
> *if*(code == 0){
>
> *return*0; // Return on the main Selector and try again.
>
> }
>
> Therefore the doRead method returns 0 to the doHandshake method and
> 0==eof which is 0 so it calls sslEngine.closeInbound()
>
> *if*(/doRead/(key,inputBB,sslEngine, timeout) <= eof) {
>
> *try*{
>
> sslEngine.closeInbound();
>
> } *catch*(IOException ex){
>
> Logger logger = SSLSelectorThread./logger/();
>
> *if*( logger.isLoggable(Level./FINE/) ){
>
> logger.log(Level./FINE/,"closeInbound doHandshake",ex);
>
> }
>
> }
>
> *throw**new*EOFException("Connection closed");
>
> }
>
> 2011-09-07 14:00:30,408 INFO [STDOUT] Using SSLEngineImpl.
>
> 2011-09-07 14:00:30,408 FINE [GRIZZLY] HERE_DO_TASK
>
> 2011-09-07 14:00:30,408 DEBUG [GRIZZLY] HERE_DO_TASK
>
> 2011-09-07 14:00:30,454 INFO [STDOUT] Allow unsafe renegotiation: false
>
> Allow legacy hello messages: true
>
> Is initial handshake: true
>
> Is secure renegotiation: false
>
> 2011-09-07 14:00:30,454 FINE [GRIZZLY] inputBB 0
>
> 2011-09-07 14:00:30,454 DEBUG [GRIZZLY] inputBB 0
>
> 2011-09-07 14:00:30,454 FINE [GRIZZLY] handshakeStatus NEED_UNWRAP
>
> 2011-09-07 14:00:30,454 DEBUG [GRIZZLY] handshakeStatus NEED_UNWRAP
>
> 2011-09-07 14:00:30,454 FINE [GRIZZLY] timeout 30000
>
> 2011-09-07 14:00:30,454 DEBUG [GRIZZLY] timeout 30000
>
> 2011-09-07 14:00:30,454 FINE [GRIZZLY] eof 0
>
> 2011-09-07 14:00:30,454 DEBUG [GRIZZLY] eof 0
>
> 2011-09-07 14:00:30,454 FINE [GRIZZLY] handshakeStatus NEED_UNWRAP
>
> 2011-09-07 14:00:30,454 DEBUG [GRIZZLY] handshakeStatus NEED_UNWRAP
>
> 2011-09-07 14:00:30,454 FINE [GRIZZLY] key
> sun.nio.ch.SelectionKeyImpl_at_35684d
>
> 2011-09-07 14:00:30,454 DEBUG [GRIZZLY] key
> sun.nio.ch.SelectionKeyImpl_at_35684d
>
> 2011-09-07 14:00:30,454 FINE [GRIZZLY] timeout in doHandshake 30000
>
> 2011-09-07 14:00:30,454 DEBUG [GRIZZLY] timeout in doHandshake 30000
>
> 2011-09-07 14:00:30,454 FINE [GRIZZLY] preReadInputBBPos 0
>
> 2011-09-07 14:00:30,454 DEBUG [GRIZZLY] preReadInputBBPos 0
>
> 2011-09-07 14:00:30,454 FINE [GRIZZLY] count 0
>
> 2011-09-07 14:00:30,454 DEBUG [GRIZZLY] count 0
>
> 2011-09-07 14:00:30,454 FINE [GRIZZLY] byteRead1 0
>
> 2011-09-07 14:00:30,454 DEBUG [GRIZZLY] byteRead1 0
>
> 2011-09-07 14:00:30,454 FINE [GRIZZLY] byteRead2 0
>
> 2011-09-07 14:00:30,454 DEBUG [GRIZZLY] byteRead2 0
>
> 2011-09-07 14:00:30,470 FINE [GRIZZLY] timeout in doRead 30000
>
> 2011-09-07 14:00:30,470 DEBUG [GRIZZLY] timeout in doRead 30000
>
> 2011-09-07 14:01:00,448 FINE [GRIZZLY] code is
> readSelector.select(timeout)
>
> 2011-09-07 14:01:00,448 DEBUG [GRIZZLY] code is
> readSelector.select(timeout)
>
> 2011-09-07 14:01:00,448 FINE [GRIZZLY] code is 0
>
> 2011-09-07 14:01:00,448 DEBUG [GRIZZLY] code is 0
>
> 2011-09-07 14:01:00,448 FINE [GRIZZLY] timeout in doHandshake after
> doRead 30000
>
> 2011-09-07 14:01:00,448 DEBUG [GRIZZLY] timeout in doHandshake after
> doRead 30000
>
> 2011-09-07 14:01:00,448 INFO [STDOUT] httpWorkerThread-9181-3, called
> closeInbound()
>
> 2011-09-07 14:01:00,448 INFO [STDOUT] httpWorkerThread-9181-3, fatal
> error: 80: Inbound closed before receiving peer's close_notify:
> possible truncation attack?
>
> javax.net.ssl.SSLException: Inbound closed before receiving peer's
> close_notify: possible truncation attack?
>
> 2011-09-07 14:01:00,448 INFO [STDOUT] httpWorkerThread-9181-3
>
> 2011-09-07 14:01:00,448 INFO [STDOUT] , SEND TLSv1 ALERT:
>
> 2011-09-07 14:01:00,448 INFO [STDOUT] fatal,
>
> 2011-09-07 14:01:00,448 INFO [STDOUT] description = internal_error
>
> 2011-09-07 14:01:00,448 INFO [STDOUT] httpWorkerThread-9181-3, WRITE:
> TLSv1 Alert, length = 2
>
> 2011-09-07 14:01:00,448 FINE [GRIZZLY] closeInbound doHandshake
>
> 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:190)
>
> at
> com.sun.net.ssl.internal.ssl.SSLEngineImpl.fatal(SSLEngineImpl.java:1429)
>
> at
> com.sun.net.ssl.internal.ssl.SSLEngineImpl.fatal(SSLEngineImpl.java:1397)
>
> at
> com.sun.net.ssl.internal.ssl.SSLEngineImpl.closeInbound(SSLEngineImpl.java:1336)
>
> at
> com.sun.enterprise.web.connector.grizzly.ssl.SSLUtils.doHandshake(SSLUtils.java:368)
>
> at
> com.sun.enterprise.web.connector.grizzly.ssl.SSLReadTask.doHandshake(SSLReadTask.java:300)
>
> at
> com.sun.enterprise.web.connector.grizzly.ssl.SSLReadTask.doTask(SSLReadTask.java:216)
>
> at
> com.sun.enterprise.web.connector.grizzly.TaskBase.run(TaskBase.java:264)
>
> at
> com.sun.enterprise.web.connector.grizzly.ssl.SSLWorkerThread.run(SSLWorkerThread.java:106)
>
> *From:*Oleksiy Stashok [mailto:oleksiy.stashok_at_oracle.com]
> *Sent:* Monday, September 05, 2011 1:56 AM
> *To:* users_at_grizzly.java.net
> *Subject:* Re: Grizzly SSL Connection Closed Error
>
> Hi,
>
> the problem happens during SSL handshake, so most probably it's
> related to Grizzly's SSL configuration.
> Can you pls. give us more details how you use Grizzly, cause you
> mentioned JBoss etc.
>
> Thanks.
>
> WBR,
> Alexey.
>
> On 09/02/2011 08:29 PM, Bessette-Halsema, Dominique E wrote:
>
> Hi
>
> I'm getting a EOFException: Connection Closed error when I try to hit
> my wsdl using two-way ssl. I edited the grizzly source code to call
> the SSLWorkerThreadclass instead of the WorkerThreadImpl class in
> LinkedListPipeline because I was getting a ClassCastException when
> using two-way ssl:
>
> 16:06:50,796 INFO [STDOUT] Using SSLEngineImpl.
>
> 16:06:50,796 FINE [GRIZZLY]
> workerThread.httpExceptionjava.lang.ClassCastException:
>
> com.sun.enterprise.web.connector.grizzly.WorkerThreadImpl cannot be
> cast to com.sun.enterprise.web.connector.grizzly.ssl.SSLWorkerThread
>
> at
> com.sun.enterprise.web.connector.grizzly.ssl.SSLReadTask.doTask(SSLReadTask.java:208)
>
> at
> com.sun.enterprise.web.connector.grizzly.TaskBase.run(TaskBase.java:264)
>
> at
> com.sun.enterprise.web.connector.grizzly.WorkerThreadImpl.run(WorkerThreadImpl.java:117)
>
> 16:06:50,796 DEBUG [GRIZZLY] workerThread.httpException
>
> java.lang.ClassCastException:
> com.sun.enterprise.web.connector.grizzly.WorkerThreadImpl cannot be
> cast to com.sun.enterprise.web.connector.grizzly.ssl.SSLWorkerThread
>
> at
> com.sun.enterprise.web.connector.grizzly.ssl.SSLReadTask.doTask(SSLReadTask.java:208)
>
> at
> com.sun.enterprise.web.connector.grizzly.TaskBase.run(TaskBase.java:264)
>
> at
> com.sun.enterprise.web.connector.grizzly.WorkerThreadImpl.run(WorkerThreadImpl.java:117)
>
> Some info I also attached the log file:
>
> I'm deploying a servicemix-3.3.1 war in JBoss 5.1.0 using Grizzly
> version 1.0.30 I tried updating to 1.0.40 and saw no difference in error
>
> Grizzly 1.0.30 running on Windows XP-5.1 under JDK version:
> 1.6.0_26-Sun Microsystems Inc.
>
> port: 9080
>
> maxThreads: 5
>
> ByteBuffer size: 8192
>
> useDirectByteBuffer: 8192
>
> maxKeepAliveRequests: 256
>
> keepAliveTimeoutInSeconds: 30
>
> Static File Cache enabled: false
>
> Pipeline :
> com.sun.jbi.httpsoapbc.embedded.LinkedListThrottlePipeline
>
> Round Robin Selector Algorithm enabled: false
>
> Round Robin Selector pool size: 0
>
> Asynchronous Request Processing enabled: true
>
> Here are the sun-http-binding config properties for servicemix
>
> ClientAuthEnabled=true
>
> NonProxyHosts=localhost|127.0.0.1
>
> ProxyPort=0
>
> HttpDefaultPort=9080
>
> ProxyPassword=
>
> ProxyUserName=
>
> ProxyType=DIRECT
>
> UseJVMProxySettings=false
>
> ProxyHost=
>
> HttpsDefaultPort=9181
>
> OutboundThreads=100
>
> And then I receive this error when I try to hit the deployed composite
> service with two-way SSL
>
> 2011-09-02 11:01:58,257 INFO [STDOUT] Using SSLEngineImpl.
>
> 2011-09-02 11:02:28,491 INFO [STDOUT] httpWorkerThread-9181-3, called
> closeInbound()
>
> 2011-09-02 11:02:28,491 INFO [STDOUT] httpWorkerThread-9181-3,
> closeInboundInternal()
>
> 2011-09-02 11:02:28,491 INFO [STDOUT] httpWorkerThread-9181-3,
> closeOutboundInternal()
>
> 2011-09-02 11:02:28,491 FINE [GRIZZLY] doHandshake
>
> java.io.EOFException: Connection closed
>
> at
> com.sun.enterprise.web.connector.grizzly.ssl.SSLUtils.doHandshake(SSLUtils.java:355)
>
> at
> com.sun.enterprise.web.connector.grizzly.ssl.SSLReadTask.doHandshake(SSLReadTask.java:291)
>
> at
> com.sun.enterprise.web.connector.grizzly.ssl.SSLReadTask.doTask(SSLReadTask.java:214)
>
> at
> com.sun.enterprise.web.connector.grizzly.TaskBase.run(TaskBase.java:264)
>
> at
> com.sun.enterprise.web.connector.grizzly.ssl.SSLWorkerThread.run(SSLWorkerThread.java:106)
>
> 2011-09-02 11:02:28,491 DEBUG [GRIZZLY] doHandshake
>
> java.io.EOFException: Connection closed
>
> at
> com.sun.enterprise.web.connector.grizzly.ssl.SSLUtils.doHandshake(SSLUtils.java:355)
>
> at
> com.sun.enterprise.web.connector.grizzly.ssl.SSLReadTask.doHandshake(SSLReadTask.java:291)
>
> at
> com.sun.enterprise.web.connector.grizzly.ssl.SSLReadTask.doTask(SSLReadTask.java:214)
>
> at
> com.sun.enterprise.web.connector.grizzly.TaskBase.run(TaskBase.java:264)
>
> at
> com.sun.enterprise.web.connector.grizzly.ssl.SSLWorkerThread.run(SSLWorkerThread.java:106)
>
> 2011-09-02 11:02:28,491 INFO [STDOUT] Using SSLEngineImpl.
>
> Thank You for your help
>