You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@mina.apache.org by el...@apache.org on 2010/01/11 01:45:56 UTC

svn commit: r897742 - in /mina/trunk: core/src/main/java/org/apache/mina/filter/ssl/SslFilter.java core/src/main/java/org/apache/mina/filter/ssl/SslHandler.java example/src/test/resources/ example/src/test/resources/log4j.properties

Author: elecharny
Date: Mon Jan 11 00:45:56 2010
New Revision: 897742

URL: http://svn.apache.org/viewvc?rev=897742&view=rev
Log:
o Added logs in SslFilter
o Added new comments and Javadoc
o Separated the init() from the construction of the SslHandler()
o Renamed the SslHandler.parent object to sslFilter for clarity sake
o Removed the duplicated sslContext field
o Forbid wrong setup of SSL flag when in Client Mode
o Rename the decrypt() method to unwrap() to be closer to the SSLEngine semantic
o No need to pass this method a parameter, so removed it
o Removed a useless condition in the unwrap loop : (finished || handshakeComplete) is always true if the status is OK or BUFFER_OVERFLOW
o Added a ToString method

Added:
    mina/trunk/example/src/test/resources/
    mina/trunk/example/src/test/resources/log4j.properties
Modified:
    mina/trunk/core/src/main/java/org/apache/mina/filter/ssl/SslFilter.java
    mina/trunk/core/src/main/java/org/apache/mina/filter/ssl/SslHandler.java

Modified: mina/trunk/core/src/main/java/org/apache/mina/filter/ssl/SslFilter.java
URL: http://svn.apache.org/viewvc/mina/trunk/core/src/main/java/org/apache/mina/filter/ssl/SslFilter.java?rev=897742&r1=897741&r2=897742&view=diff
==============================================================================
--- mina/trunk/core/src/main/java/org/apache/mina/filter/ssl/SslFilter.java (original)
+++ mina/trunk/core/src/main/java/org/apache/mina/filter/ssl/SslFilter.java Mon Jan 11 00:45:56 2010
@@ -42,6 +42,8 @@
 import org.apache.mina.core.write.WriteRequest;
 import org.apache.mina.core.write.WriteRequestWrapper;
 import org.apache.mina.core.write.WriteToClosedSessionException;
+import org.slf4j.Logger;
+import org.slf4j.LoggerFactory;
 
 /**
  * An SSL filter that encrypts and decrypts the data exchanged in the session.
@@ -84,6 +86,9 @@
  * @org.apache.xbean.XBean
  */
 public class SslFilter extends IoFilterAdapter {
+    /** The logger */
+    private static final Logger LOGGER = LoggerFactory.getLogger( SslFilter.class );
+
     /**
      * A session attribute key that stores underlying {@link SSLSession}
      * for each session.
@@ -146,7 +151,7 @@
     private static final AttributeKey SSL_HANDLER = new AttributeKey(SslFilter.class, "handler");
 
     /** The SslContext used */
-    private final SSLContext sslContext;
+    /* No qualifier */ final SSLContext sslContext;
 
     /** A flag used to tell the filter to start the handshake immediately */
     private final boolean autoStart;
@@ -225,7 +230,7 @@
 
     /**
      * Returns <tt>true</tt> if and only if the specified <tt>session</tt> is
-     * encrypted/decrypted over SSL/TLS currently.  This method will start
+     * encrypted/decrypted over SSL/TLS currently. This method will start
      * to return <tt>false</tt> after TLS <tt>close_notify</tt> message
      * is sent and any messages written after then is not going to get encrypted.
      */
@@ -349,19 +354,33 @@
         this.enabledProtocols = protocols;
     }
 
+    /**
+     * Executed just before the filter is added into the chain, we do :
+     * <ul>
+     * <li>check that we don't have a SSL filter already present
+     * <li>we update the next filter
+     * <li>we create the SSL handler helper class
+     * <li>and we store it into the session's Attributes
+     * </ul>
+     */
     @Override
     public void onPreAdd(IoFilterChain parent, String name,
             NextFilter nextFilter) throws SSLException {
+        // Check that we don't have a SSL filter already present in the chain
         if (parent.contains(SslFilter.class)) {
-            throw new IllegalStateException(
-                    "Only one " + SslFilter.class.getName() + " is permitted.");
+            String msg = "Only one SSL filter is permitted in a chain.";
+            LOGGER.error(msg);
+            throw new IllegalStateException(msg);
         }
 
+        LOGGER.debug("Adding the SSL Filter {} to the chain", name);
+
         IoSession session = parent.getSession();
         session.setAttribute(NEXT_FILTER, nextFilter);
 
-        // Create an SSL handler and start handshake.
-        SslHandler handler = new SslHandler(this, sslContext, session);
+        // Create a SSL handler and start handshake.
+        SslHandler handler = new SslHandler(this, session);
+        handler.init();
         session.setAttribute(SSL_HANDLER, handler);
     }
 
@@ -403,10 +422,21 @@
     @Override
     public void messageReceived(NextFilter nextFilter, IoSession session,
             Object message) throws SSLException {
+        if ( LOGGER.isDebugEnabled()) {
+            if ( isSslStarted(session)) {
+                LOGGER.debug("Session[{}](SSL): Message received : {}", session.getId(), message);
+            } else {
+                LOGGER.debug("Session[{}]: Message received : {}", session.getId(), message);
+            }
+        }
+        
         SslHandler handler = getSslSessionHandler(session);
         
         synchronized (handler) {
             if (!isSslStarted(session) && handler.isInboundDone()) {
+                // The SSL session must be established first before we 
+                // can push data to the application. Store the incoming
+                // data into a queue for a later processing
                 handler.scheduleMessageReceived(nextFilter, message);
             } else {
                 IoBuffer buf = (IoBuffer) message;
@@ -517,6 +547,14 @@
     @Override
     public void filterWrite(NextFilter nextFilter, IoSession session,
             WriteRequest writeRequest) throws SSLException {
+        if ( LOGGER.isDebugEnabled()) {
+            if ( isSslStarted(session)) {
+                LOGGER.debug("Session[{}](SSL): Writing Message : {}", session.getId(), writeRequest);
+            } else {
+                LOGGER.debug("Session[{}]: Writing Message : {}", session.getId(), writeRequest);
+            }
+        }
+
         boolean needsFlush = true;
         SslHandler handler = getSslSessionHandler(session);
         synchronized (handler) {
@@ -597,6 +635,7 @@
 
     private void initiateHandshake(NextFilter nextFilter, IoSession session)
             throws SSLException {
+        LOGGER.debug("Session[{}] : Starting the first handshake", session.getId());
         SslHandler handler = getSslSessionHandler(session);
         
         synchronized (handler) {
@@ -609,6 +648,7 @@
     private WriteFuture initiateClosure(NextFilter nextFilter, IoSession session)
             throws SSLException {
         SslHandler handler = getSslSessionHandler(session);
+        
         // if already shut down
         if (!handler.closeOutbound()) {
             return DefaultWriteFuture.newNotWrittenFuture(
@@ -617,6 +657,7 @@
 
         // there might be data to write out here?
         WriteFuture future = handler.writeNetBuffer(nextFilter);
+        
         if (future == null) {
             future = DefaultWriteFuture.newWrittenFuture(session);
         }
@@ -632,10 +673,19 @@
         return future;
     }
 
-    // Utiliities
-
+    // Utilities
     private void handleSslData(NextFilter nextFilter, SslHandler handler)
             throws SSLException {
+        if ( LOGGER.isDebugEnabled()) {
+            IoSession session = handler.getSession();
+            
+            if ( isSslStarted(session)) {
+                LOGGER.debug("Session[{}](SSL): Processing the SSL Data ", session.getId());
+            } else {
+                LOGGER.debug("Session[{}]: Processing the SSL Data message", session.getId());
+            }
+        }
+
         // Flush any buffered write requests occurred before handshaking.
         if (handler.isHandshakeComplete()) {
             handler.flushPreHandshakeEvents();
@@ -651,6 +701,7 @@
     private void handleAppDataRead(NextFilter nextFilter, SslHandler handler) {
         // forward read app data
         IoBuffer readBuffer = handler.fetchAppBuffer();
+        
         if (readBuffer.hasRemaining()) {
             handler.scheduleMessageReceived(nextFilter, readBuffer);
         }
@@ -663,7 +714,7 @@
             throw new IllegalStateException();
         }
         
-        if (handler.getParent() != this) {
+        if (handler.getSslFilter() != this) {
             throw new IllegalArgumentException("Not managed by this filter.");
         }
         

Modified: mina/trunk/core/src/main/java/org/apache/mina/filter/ssl/SslHandler.java
URL: http://svn.apache.org/viewvc/mina/trunk/core/src/main/java/org/apache/mina/filter/ssl/SslHandler.java?rev=897742&r1=897741&r2=897742&view=diff
==============================================================================
--- mina/trunk/core/src/main/java/org/apache/mina/filter/ssl/SslHandler.java (original)
+++ mina/trunk/core/src/main/java/org/apache/mina/filter/ssl/SslHandler.java Mon Jan 11 00:45:56 2010
@@ -24,7 +24,6 @@
 import java.util.Queue;
 import java.util.concurrent.ConcurrentLinkedQueue;
 
-import javax.net.ssl.SSLContext;
 import javax.net.ssl.SSLEngine;
 import javax.net.ssl.SSLEngineResult;
 import javax.net.ssl.SSLException;
@@ -52,18 +51,27 @@
  * We allocate buffers for use as the outbound and inbound network buffers.
  * These buffers handle all of the intermediary data for the SSL connection. To make things easy,
  * we'll require outNetBuffer be completely flushed before trying to wrap any more data.
+ * <p/>
+ * This class is not to be used by any client, it's closely associated with the SSL Filter.
  *
  * @author <a href="http://mina.apache.org">Apache MINA Project</a>
  */
-class SslHandler {
-
+/** No qualifier*/ class SslHandler {
+    /** A logger for this class */
     private final static Logger LOGGER = LoggerFactory.getLogger(SslHandler.class);
-    private final SslFilter parent;
-    private final SSLContext sslContext;
+    
+    /** The SSL Filter which has created this handler */
+    private final SslFilter sslFilter;
+    
+    /** The current session */
     private final IoSession session;
+    
     private final Queue<IoFilterEvent> preHandshakeEventQueue = new CircularQueue<IoFilterEvent>();
     private final Queue<IoFilterEvent> filterWriteEventQueue = new ConcurrentLinkedQueue<IoFilterEvent>();
+    
+    /** A queue used to stack all the incoming data until the SSL session is established */
     private final Queue<IoFilterEvent> messageReceivedEventQueue = new ConcurrentLinkedQueue<IoFilterEvent>();
+    
     private SSLEngine sslEngine;
 
     /**
@@ -87,30 +95,37 @@
     private final IoBuffer emptyBuffer = IoBuffer.allocate(0);
 
     private SSLEngineResult.HandshakeStatus handshakeStatus;
-    private boolean initialHandshakeComplete;
+    
+    /** 
+     * A flag set to true when the first SSL handshake has been completed
+     * This is used to avoid sending a notification to the application handler
+     * when we switch to a SECURE or UNSECURE session. 
+     */
+    private boolean firstSSLNegociation;
+    
+    /** A flag set to true when a SSL Handshake has been completed */
     private boolean handshakeComplete;
+    
+    /** A flag used to indicate to the SslFilter that the buffer
+     * it will write is already encrypted (this will be the case
+     * for data being produced during the handshake). */
     private boolean writingEncryptedData;
 
-    /** A flag used when the Handlshake is finished */
-    private static final boolean HANDSHAKE_FINISHED = true;
-
     /**
-     * Constuctor.
+     * Create a new SSL Handler, and initialize it.
      *
-     * @param sslc
+     * @param sslContext
      * @throws SSLException
      */
-    public SslHandler(SslFilter parent, SSLContext sslContext, IoSession session) throws SSLException {
-        this.parent = parent;
+    public SslHandler(SslFilter sslFilter, IoSession session) throws SSLException {
+        this.sslFilter = sslFilter;
         this.session = session;
-        this.sslContext = sslContext;
-        init();
     }
 
     /**
      * Initialize the SSL handshake.
      *
-     * @throws SSLException
+     * @throws SSLException If the underlying SSLEngine handshake initialization failed
      */
     public void init() throws SSLException {
         if (sslEngine != null) {
@@ -118,45 +133,60 @@
             return;
         }
 
+        LOGGER.debug("Session[{}]: Initializing the SSL Handler", session.getId());
+
         InetSocketAddress peer = (InetSocketAddress) session.getAttribute(SslFilter.PEER_ADDRESS);
 
         // Create the SSL engine here
         if (peer == null) {
-            sslEngine = sslContext.createSSLEngine();
+            sslEngine = sslFilter.sslContext.createSSLEngine();
         } else {
-            sslEngine = sslContext.createSSLEngine(peer.getHostName(), peer.getPort());
+            sslEngine = sslFilter.sslContext.createSSLEngine(peer.getHostName(), peer.getPort());
         }
 
         // Initialize the engine in client mode if necessary
-        sslEngine.setUseClientMode(parent.isUseClientMode());
+        sslEngine.setUseClientMode(sslFilter.isUseClientMode());
 
         // Initialize the different SslEngine modes
-        if (parent.isWantClientAuth()) {
-            sslEngine.setWantClientAuth(true);
-        }
+        if (!sslEngine.getUseClientMode()) {
+            // Those parameters are only valid when in server mode
+            if (sslFilter.isWantClientAuth()) {
+                sslEngine.setWantClientAuth(true);
+            }
 
-        if (parent.isNeedClientAuth()) {
-            sslEngine.setNeedClientAuth(true);
+            if (sslFilter.isNeedClientAuth()) {
+                sslEngine.setNeedClientAuth(true);
+            }
         }
 
-        if (parent.getEnabledCipherSuites() != null) {
-            sslEngine.setEnabledCipherSuites(parent.getEnabledCipherSuites());
+        // Set the cipher suite to use by this SslEngine instance
+        if (sslFilter.getEnabledCipherSuites() != null) {
+            sslEngine.setEnabledCipherSuites(sslFilter.getEnabledCipherSuites());
         }
 
-        if (parent.getEnabledProtocols() != null) {
-            sslEngine.setEnabledProtocols(parent.getEnabledProtocols());
+        // Set the list of enabled protocols
+        if (sslFilter.getEnabledProtocols() != null) {
+            sslEngine.setEnabledProtocols(sslFilter.getEnabledProtocols());
         }
 
         // TODO : we may not need to call this method...
+        // However, if we don't call it here, the tests are failing. Why?
         sslEngine.beginHandshake();
 
         handshakeStatus = sslEngine.getHandshakeStatus();
 
-        handshakeComplete = false;
-        initialHandshakeComplete = false;
+        // Default value
         writingEncryptedData = false;
+        
+        // We haven't yet started a SSL negotiation
+        // set the flags accordingly
+        firstSSLNegociation = true;
+        handshakeComplete = false;
+
+        LOGGER.debug("Session[{}]: SSL Handler Initialization done.", session.getId());
     }
 
+    
     /**
      * Release allocated buffers.
      */
@@ -198,8 +228,11 @@
         outNetBuffer = null;
     }
 
-    public SslFilter getParent() {
-        return parent;
+    /**
+     * @return The SSL filter which has created this handler
+     */
+    public SslFilter getSslFilter() {
+        return sslFilter;
     }
 
     public IoSession getSession() {
@@ -207,7 +240,7 @@
     }
 
     /**
-     * Check we are writing encrypted data.
+     * Check if we are writing encrypted data.
      */
     public boolean isWritingEncryptedData() {
         return writingEncryptedData;
@@ -243,7 +276,7 @@
         IoFilterEvent scheduledWrite;
 
         while ((scheduledWrite = preHandshakeEventQueue.poll()) != null) {
-            parent.filterWrite(scheduledWrite.getNextFilter(), session, (WriteRequest) scheduledWrite.getParameter());
+            sslFilter.filterWrite(scheduledWrite.getNextFilter(), session, (WriteRequest) scheduledWrite.getParameter());
         }
     }
 
@@ -251,6 +284,13 @@
         filterWriteEventQueue.add(new IoFilterEvent(nextFilter, IoEventType.WRITE, session, writeRequest));
     }
 
+    /**
+     * Push the newly received data into a queue, waiting for the SSL session
+     * to be fully established
+     *
+     * @param nextFilter The next filter to call
+     * @param message The incoming data
+     */
     public void scheduleMessageReceived(NextFilter nextFilter, Object message) {
         messageReceivedEventQueue.add(new IoFilterEvent(nextFilter, IoEventType.MESSAGE_RECEIVED, session, message));
     }
@@ -261,18 +301,20 @@
             return;
         }
 
-        IoFilterEvent e;
+        IoFilterEvent event;
 
         // We need synchronization here inevitably because filterWrite can be
         // called simultaneously and cause 'bad record MAC' integrity error.
         synchronized (this) {
-            while ((e = filterWriteEventQueue.poll()) != null) {
-                e.getNextFilter().filterWrite(session, (WriteRequest) e.getParameter());
+            while ((event = filterWriteEventQueue.poll()) != null) {
+                NextFilter nextFilter = event.getNextFilter();
+                nextFilter.filterWrite(session, (WriteRequest) event.getParameter());
             }
         }
 
-        while ((e = messageReceivedEventQueue.poll()) != null) {
-            e.getNextFilter().messageReceived(session, e.getParameter());
+        while ((event = messageReceivedEventQueue.poll()) != null) {
+            NextFilter nextFilter = event.getNextFilter();
+            nextFilter.messageReceived(session, event.getParameter());
         }
     }
 
@@ -285,6 +327,14 @@
      * @throws SSLException on errors
      */
     public void messageReceived(NextFilter nextFilter, ByteBuffer buf) throws SSLException {
+        if ( LOGGER.isDebugEnabled()) {
+            if ( !isOutboundDone()) {
+                LOGGER.debug("Session[{}](SSL): Processing the received message", session.getId());
+            } else {
+                LOGGER.debug("Session[{}]: Processing the received message", session.getId());
+            }
+        }
+
         // append buf to inNetBuffer
         if (inNetBuffer == null) {
             inNetBuffer = IoBuffer.allocate(buf.remaining()).setAutoExpand(true);
@@ -302,7 +352,7 @@
                 return;
             }
 
-            SSLEngineResult res = decrypt(!HANDSHAKE_FINISHED);
+            SSLEngineResult res = unwrap();
 
             // prepare to be written again
             if (inNetBuffer.hasRemaining()) {
@@ -455,64 +505,78 @@
     public void handshake(NextFilter nextFilter) throws SSLException {
         for (;;) {
             switch (handshakeStatus) {
-            case FINISHED:
-                session.setAttribute(SslFilter.SSL_SESSION, sslEngine.getSession());
-                handshakeComplete = true;
-
-                if (!initialHandshakeComplete && session.containsAttribute(SslFilter.USE_NOTIFICATION)) {
-                    // SESSION_SECURED is fired only when it's the first
-                    // handshake.
-                    // (i.e. renegotiation shouldn't trigger SESSION_SECURED.)
-                    initialHandshakeComplete = true;
-                    scheduleMessageReceived(nextFilter, SslFilter.SESSION_SECURED);
-                }
-
-                return;
-
-            case NEED_TASK:
-                handshakeStatus = doTasks();
-                break;
-
-            case NEED_UNWRAP:
-                // we need more data read
-                SSLEngineResult.Status status = unwrapHandshake(nextFilter);
-
-                if (status == SSLEngineResult.Status.BUFFER_UNDERFLOW
-                        && handshakeStatus != SSLEngineResult.HandshakeStatus.FINISHED || isInboundDone()) {
-                    // We need more data or the session is closed
-                    return;
-                }
-
-                break;
-
-            case NEED_WRAP:
-                // First make sure that the out buffer is completely empty.
-                // Since we
-                // cannot call wrap with data left on the buffer
-                if (outNetBuffer != null && outNetBuffer.hasRemaining()) {
+                case FINISHED:
+                    LOGGER.debug("Session[{}] : processing the FINISHED state", session.getId());
+                    session.setAttribute(SslFilter.SSL_SESSION, sslEngine.getSession());
+                    handshakeComplete = true;
+    
+                    // Send the SECURE message only if it's the first SSL handshake
+                    if (firstSSLNegociation && session.containsAttribute(SslFilter.USE_NOTIFICATION)) {
+                        // SESSION_SECURED is fired only when it's the first handshake
+                        firstSSLNegociation = false;
+                        scheduleMessageReceived(nextFilter, SslFilter.SESSION_SECURED);
+                    }
+                    
+                    if ( LOGGER.isDebugEnabled()) {
+                        if ( !isOutboundDone()) {
+                            LOGGER.debug("Session[{}] is now secured", session.getId());
+                        } else {
+                            LOGGER.debug("Session[{}] is not secured yet", session.getId());
+                        }
+                    }
+    
                     return;
-                }
-
-                SSLEngineResult result;
-                createOutNetBuffer(0);
-
-                for (;;) {
-                    result = sslEngine.wrap(emptyBuffer.buf(), outNetBuffer.buf());
-                    if (result.getStatus() == SSLEngineResult.Status.BUFFER_OVERFLOW) {
-                        outNetBuffer.capacity(outNetBuffer.capacity() << 1);
-                        outNetBuffer.limit(outNetBuffer.capacity());
-                    } else {
-                        break;
+    
+                case NEED_TASK:
+                    LOGGER.debug("Session[{}] : processing the NEED_TASK state", session.getId());
+                    handshakeStatus = doTasks();
+                    break;
+    
+                case NEED_UNWRAP:
+                    LOGGER.debug("Session[{}] : processing the NEED_UNWRAP state", session.getId());
+                    // we need more data read
+                    SSLEngineResult.Status status = unwrapHandshake(nextFilter);
+    
+                    if (status == SSLEngineResult.Status.BUFFER_UNDERFLOW
+                            && handshakeStatus != SSLEngineResult.HandshakeStatus.FINISHED || isInboundDone()) {
+                        // We need more data or the session is closed
+                        return;
                     }
-                }
-
-                outNetBuffer.flip();
-                handshakeStatus = result.getHandshakeStatus();
-                writeNetBuffer(nextFilter);
-                break;
-
-            default:
-                throw new IllegalStateException("Invalid Handshaking State" + handshakeStatus);
+    
+                    break;
+    
+                case NEED_WRAP:
+                    LOGGER.debug("Session[{}] : processing the NEED_WRAP state", session.getId());
+                    // First make sure that the out buffer is completely empty.
+                    // Since we
+                    // cannot call wrap with data left on the buffer
+                    if (outNetBuffer != null && outNetBuffer.hasRemaining()) {
+                        return;
+                    }
+    
+                    SSLEngineResult result;
+                    createOutNetBuffer(0);
+    
+                    for (;;) {
+                        result = sslEngine.wrap(emptyBuffer.buf(), outNetBuffer.buf());
+                        if (result.getStatus() == SSLEngineResult.Status.BUFFER_OVERFLOW) {
+                            outNetBuffer.capacity(outNetBuffer.capacity() << 1);
+                            outNetBuffer.limit(outNetBuffer.capacity());
+                        } else {
+                            break;
+                        }
+                    }
+    
+                    outNetBuffer.flip();
+                    handshakeStatus = result.getHandshakeStatus();
+                    writeNetBuffer(nextFilter);
+                    break;
+    
+                default:
+                    String msg = "Invalid Handshaking State" + handshakeStatus + 
+                        " while processing the Handshake for session " + session.getId();
+                    LOGGER.error(msg);
+                    throw new IllegalStateException(msg);
             }
         }
     }
@@ -546,7 +610,7 @@
         try {
             IoBuffer writeBuffer = fetchOutNetBuffer();
             writeFuture = new DefaultWriteFuture(session);
-            parent.filterWrite(nextFilter, session, new DefaultWriteRequest(writeBuffer, writeFuture));
+            sslFilter.filterWrite(nextFilter, session, new DefaultWriteRequest(writeBuffer, writeFuture));
 
             // loop while more writes required to complete handshake
             while (needToCompleteHandshake()) {
@@ -561,7 +625,7 @@
                 IoBuffer outNetBuffer = fetchOutNetBuffer();
                 if (outNetBuffer != null && outNetBuffer.hasRemaining()) {
                     writeFuture = new DefaultWriteFuture(session);
-                    parent.filterWrite(nextFilter, session, new DefaultWriteRequest(outNetBuffer, writeFuture));
+                    sslFilter.filterWrite(nextFilter, session, new DefaultWriteRequest(outNetBuffer, writeFuture));
                 }
             }
         } finally {
@@ -582,17 +646,16 @@
             return SSLEngineResult.Status.BUFFER_UNDERFLOW;
         }
 
-        SSLEngineResult res = decrypt(!HANDSHAKE_FINISHED);
+        SSLEngineResult res = unwrap();
         handshakeStatus = res.getHandshakeStatus();
 
         checkStatus(res);
 
         // If handshake finished, no data was produced, and the status is still
-        // ok,
-        // try to unwrap more
+        // ok, try to unwrap more
         if (handshakeStatus == SSLEngineResult.HandshakeStatus.FINISHED && res.getStatus() == SSLEngineResult.Status.OK
                 && inNetBuffer.hasRemaining()) {
-            res = decrypt(HANDSHAKE_FINISHED);
+            res = unwrap();
 
             // prepare to be written again
             if (inNetBuffer.hasRemaining()) {
@@ -625,10 +688,16 @@
         }
     }
 
-    private SSLEngineResult decrypt(boolean finished) throws SSLException {
+    /**
+     * Decrypt the incoming buffer and move the decrypted data to an
+     * application buffer. 
+     */
+    private SSLEngineResult unwrap() throws SSLException {
+        // We first have to create the application buffer if it does not exist
         if (appBuffer == null) {
             appBuffer = IoBuffer.allocate(inNetBuffer.remaining());
         } else {
+            // We already have one, just add the new data into it
             appBuffer.expand(inNetBuffer.remaining());
         }
 
@@ -638,27 +707,29 @@
         HandshakeStatus handshakeStatus = null;
 
         do {
+            // Decode the incoming data
             res = sslEngine.unwrap(inNetBuffer.buf(), appBuffer.buf());
             status = res.getStatus();
+            
+            // We can be processing the Handshake
             handshakeStatus = res.getHandshakeStatus();
 
             if (status == SSLEngineResult.Status.BUFFER_OVERFLOW) {
+                // We have to grow the target buffer, it's too small.
+                // Then we can call the unwrap method again
                 appBuffer.capacity(appBuffer.capacity() << 1);
                 appBuffer.limit(appBuffer.capacity());
                 continue;
             }
         } while (
                     (
-                        (status == SSLEngineResult.Status.OK) || 
+                        (status == SSLEngineResult.Status.OK) 
+                        || 
                         (status == SSLEngineResult.Status.BUFFER_OVERFLOW)
                     )
                     &&
                     (
-                        (
-                            (finished || handshakeComplete) 
-                            && 
-                            (handshakeStatus == SSLEngineResult.HandshakeStatus.NOT_HANDSHAKING)
-                        ) 
+                        (handshakeStatus == SSLEngineResult.HandshakeStatus.NOT_HANDSHAKING)
                         || 
                         (handshakeStatus == SSLEngineResult.HandshakeStatus.NEED_UNWRAP)
                     )
@@ -698,4 +769,23 @@
         copy.flip();
         return copy;
     }
+    
+    public String toString() {
+        StringBuilder sb = new StringBuilder();
+        
+        sb.append("SSLStatus <");
+        
+        if (handshakeComplete) {
+            sb.append("SSL established");
+        } else {
+            sb.append("Processing Handshake" ).append("; ");
+            sb.append("Status : ").append(handshakeStatus).append("; ");
+        }
+        
+        sb.append(", ");
+        sb.append("HandshakeComplete :" ).append(handshakeComplete).append(", ");
+        sb.append(">");
+        return sb.toString();
+    }
+    
 }

Added: mina/trunk/example/src/test/resources/log4j.properties
URL: http://svn.apache.org/viewvc/mina/trunk/example/src/test/resources/log4j.properties?rev=897742&view=auto
==============================================================================
--- mina/trunk/example/src/test/resources/log4j.properties (added)
+++ mina/trunk/example/src/test/resources/log4j.properties Mon Jan 11 00:45:56 2010
@@ -0,0 +1,25 @@
+#############################################################################
+#    Licensed to the Apache Software Foundation (ASF) under one or more
+#    contributor license agreements.  See the NOTICE file distributed with
+#    this work for additional information regarding copyright ownership.
+#    The ASF licenses this file to You under the Apache License, Version 2.0
+#    (the "License"); you may not use this file except in compliance with
+#    the License.  You may obtain a copy of the License at
+#
+#       http://www.apache.org/licenses/LICENSE-2.0
+#
+#    Unless required by applicable law or agreed to in writing, software
+#    distributed under the License is distributed on an "AS IS" BASIS,
+#    WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+#    See the License for the specific language governing permissions and
+#    limitations under the License.
+#############################################################################
+log4j.rootCategory=ERROR, stdout
+
+log4j.appender.stdout=org.apache.log4j.ConsoleAppender
+log4j.appender.stdout.layout=org.apache.log4j.PatternLayout
+log4j.appender.stdout.layout.ConversionPattern=[%d{HH:mm:ss}] %p [%c] - %m%n
+
+log4j.logger.org.apache.mina.filter.ssl.SslFilter=ERROR
+log4j.logger.org.apache.mina.filter.ssl.SslHandler=ERROR
+