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, ByteBuffer inputBB,
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 SSLWorkerThread class 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