mirror of https://github.com/OpenIdentityPlatform/OpenDJ.git

Matthew Swift
11.17.2013 976da4aa6126aefd775b7c223c71e29d1207bf10
Fix OPENDJ-1247: Client side timeouts do not cancel bind or startTLS requests properly

* fail the connection when a bind or startTLS request times out
* ensure that abandon requests are sent for other types of operation
* added new test which tests that timeouts behave correctly in a connection pool
* re-enabled other tests.
6 files modified
286 ■■■■ changed files
opendj-ldap-sdk/src/main/java/com/forgerock/opendj/ldap/AbstractLDAPFutureResultImpl.java 23 ●●●●● patch | view | raw | blame | history
opendj-ldap-sdk/src/main/java/com/forgerock/opendj/ldap/LDAPBindFutureResultImpl.java 9 ●●●●● patch | view | raw | blame | history
opendj-ldap-sdk/src/main/java/com/forgerock/opendj/ldap/LDAPConnection.java 133 ●●●● patch | view | raw | blame | history
opendj-ldap-sdk/src/main/java/com/forgerock/opendj/ldap/LDAPExtendedFutureResultImpl.java 9 ●●●●● patch | view | raw | blame | history
opendj-ldap-sdk/src/main/resources/org/forgerock/opendj/ldap/core.properties 8 ●●●●● patch | view | raw | blame | history
opendj-ldap-sdk/src/test/java/org/forgerock/opendj/ldap/LDAPConnectionFactoryTestCase.java 104 ●●●●● patch | view | raw | blame | history
opendj-ldap-sdk/src/main/java/com/forgerock/opendj/ldap/AbstractLDAPFutureResultImpl.java
@@ -94,11 +94,34 @@
     */
    @Override
    protected final ErrorResultException handleCancelRequest(final boolean mayInterruptIfRunning) {
        /*
         * This will abandon the request, but will also recursively cancel this
         * future. There is no risk of an infinite loop because the state of
         * this future has already been changed.
         */
        connection.abandonAsync(Requests.newAbandonRequest(requestID));
        return null;
    }
    @Override
    protected final boolean isCancelable() {
        /*
         * No other operations can be performed while a bind or startTLS
         * operations is active. Therefore it is not possible to cancel bind or
         * startTLS requests, since doing so will leave the connection in a
         * state which prevents other operations from being performed.
         */
        return !isBindOrStartTLS();
    }
    /**
     * Returns {@code false} by default.
     */
    boolean isBindOrStartTLS() {
        return false;
    }
    @Override
    protected void toString(final StringBuilder sb) {
        sb.append(" requestID = ");
        sb.append(requestID);
opendj-ldap-sdk/src/main/java/com/forgerock/opendj/ldap/LDAPBindFutureResultImpl.java
@@ -22,7 +22,7 @@
 *
 *
 *      Copyright 2009-2010 Sun Microsystems, Inc.
 *      Portions copyright 2011 ForgeRock AS.
 *      Portions copyright 2011-2013 ForgeRock AS.
 */
package com.forgerock.opendj.ldap;
@@ -49,12 +49,9 @@
        this.bindClient = bindClient;
    }
    /**
     * {@inheritDoc}
     */
    @Override
    protected boolean isCancelable() {
        return false;
    boolean isBindOrStartTLS() {
        return true;
    }
    @Override
opendj-ldap-sdk/src/main/java/com/forgerock/opendj/ldap/LDAPConnection.java
@@ -28,7 +28,9 @@
package com.forgerock.opendj.ldap;
import static com.forgerock.opendj.util.StaticUtils.DEBUG_LOG;
import static org.forgerock.opendj.ldap.CoreMessages.*;
import static org.forgerock.opendj.ldap.ErrorResultException.newErrorResult;
import static org.forgerock.opendj.ldap.requests.Requests.newAbandonRequest;
import java.io.IOException;
import java.net.InetSocketAddress;
@@ -65,7 +67,6 @@
import org.forgerock.opendj.ldap.requests.GenericBindRequest;
import org.forgerock.opendj.ldap.requests.ModifyDNRequest;
import org.forgerock.opendj.ldap.requests.ModifyRequest;
import org.forgerock.opendj.ldap.requests.Requests;
import org.forgerock.opendj.ldap.requests.SearchRequest;
import org.forgerock.opendj.ldap.requests.StartTLSExtendedRequest;
import org.forgerock.opendj.ldap.requests.UnbindRequest;
@@ -128,40 +129,64 @@
    @Override
    public FutureResult<Void> abandonAsync(final AbandonRequest request) {
        final AbstractLDAPFutureResultImpl<?> pendingRequest;
        final int messageID = nextMsgID.getAndIncrement();
        /*
         * Need to be careful here since both abandonAsync and Future.cancel can
         * be called separately by the client application. Therefore
         * future.cancel() should abandon the request, and abandonAsync should
         * cancel the future. In addition, bind or StartTLS requests cannot be
         * abandoned.
         */
        try {
            synchronized (stateLock) {
                checkConnectionIsValid();
                checkBindOrStartTLSInProgress();
                // Remove the future associated with the request to be abandoned.
                pendingRequest = pendingRequests.remove(request.getRequestID());
            }
            if (pendingRequest == null) {
                /*
                 * There has never been a request with the specified message ID
                 * or the response has already been received and handled. We can
                 * ignore this abandon request.
                 * If there is a bind or startTLS in progress then it must be
                 * this request which is being abandoned. The following check
                 * will prevent it from happening.
                 */
                // Message ID will be -1 since no request was sent.
                return new CompletedFutureResult<Void>((Void) null);
            }
            pendingRequest.cancel(false);
            try {
                final ASN1BufferWriter asn1Writer = ASN1BufferWriter.getWriter();
                try {
                    ldapWriter.abandonRequest(asn1Writer, messageID, request);
                    connection.write(asn1Writer.getBuffer(), null);
                    return new CompletedFutureResult<Void>((Void) null, messageID);
                } finally {
                    asn1Writer.recycle();
                }
            } catch (final IOException e) {
                throw adaptRequestIOException(e);
                checkBindOrStartTLSInProgress();
            }
        } catch (final ErrorResultException e) {
            return new CompletedFutureResult<Void>(e, messageID);
            return new CompletedFutureResult<Void>(e);
        }
        // Remove the future associated with the request to be abandoned.
        final AbstractLDAPFutureResultImpl<?> pendingRequest =
                pendingRequests.remove(request.getRequestID());
        if (pendingRequest == null) {
            /*
             * There has never been a request with the specified message ID or
             * the response has already been received and handled. We can ignore
             * this abandon request.
             */
            return new CompletedFutureResult<Void>((Void) null);
        }
        /*
         * This will cancel the future, but will also recursively invoke this
         * method. Since the pending request has been removed, there is no risk
         * of an infinite loop.
         */
        pendingRequest.cancel(false);
        /*
         * FIXME: there's a potential race condition here if a bind or startTLS
         * is initiated just after we removed the pending request.
         */
        return sendAbandonRequest(request);
    }
    private FutureResult<Void> sendAbandonRequest(final AbandonRequest request) {
        final ASN1BufferWriter asn1Writer = ASN1BufferWriter.getWriter();
        try {
            final int messageID = nextMsgID.getAndIncrement();
            ldapWriter.abandonRequest(asn1Writer, messageID, request);
            connection.write(asn1Writer.getBuffer(), null);
            return new CompletedFutureResult<Void>((Void) null, messageID);
        } catch (final IOException e) {
            return new CompletedFutureResult<Void>(adaptRequestIOException(e));
        } finally {
            asn1Writer.recycle();
        }
    }
@@ -557,10 +582,54 @@
                if (future != null && future.checkForTimeout()) {
                    final long diff = (future.getTimestamp() + timeout) - currentTime;
                    if (diff <= 0 && pendingRequests.remove(requestID) != null) {
                        DEBUG_LOG.fine("Cancelling expired future result: " + future);
                        final Result result = Responses.newResult(ResultCode.CLIENT_SIDE_TIMEOUT);
                        future.adaptErrorResult(result);
                        abandonAsync(Requests.newAbandonRequest(future.getRequestID()));
                        if (future.isBindOrStartTLS()) {
                            /*
                             * No other operations can be performed while a bind
                             * or StartTLS request is active, so we cannot time
                             * out the request. We therefore have a choice:
                             * either ignore timeouts for these operations, or
                             * enforce them but doing so requires invalidating
                             * the connection. We'll do the latter, since
                             * ignoring timeouts could cause the application to
                             * hang.
                             */
                            DEBUG_LOG.fine("Failing bind or StartTLS request due to timeout "
                                    + "(connection will be invalidated): " + future);
                            final Result result =
                                    Responses.newResult(ResultCode.CLIENT_SIDE_TIMEOUT)
                                            .setDiagnosticMessage(
                                                    LDAP_CONNECTION_BIND_OR_START_TLS_REQUEST_TIMEOUT
                                                            .get(timeout).toString());
                            future.adaptErrorResult(result);
                            // Fail the connection.
                            final Result errorResult =
                                    Responses.newResult(ResultCode.CLIENT_SIDE_TIMEOUT)
                                            .setDiagnosticMessage(
                                                    LDAP_CONNECTION_BIND_OR_START_TLS_CONNECTION_TIMEOUT
                                                            .get(timeout).toString());
                            connectionErrorOccurred(errorResult);
                        } else {
                            DEBUG_LOG.fine("Failing request due to timeout: " + future);
                            final Result result =
                                    Responses.newResult(ResultCode.CLIENT_SIDE_TIMEOUT)
                                            .setDiagnosticMessage(
                                                    LDAP_CONNECTION_REQUEST_TIMEOUT.get(timeout)
                                                            .toString());
                            future.adaptErrorResult(result);
                            /*
                             * FIXME: there's a potential race condition here if
                             * a bind or startTLS is initiated just after we
                             * check the boolean. It seems potentially even more
                             * dangerous to send the abandon request while
                             * holding the state lock, since a blocking write
                             * could hang the application.
                             */
                            if (!bindOrStartTLSInProgress.get()) {
                                sendAbandonRequest(newAbandonRequest(requestID));
                            }
                        }
                    } else {
                        delay = Math.min(delay, diff);
                    }
opendj-ldap-sdk/src/main/java/com/forgerock/opendj/ldap/LDAPExtendedFutureResultImpl.java
@@ -22,7 +22,7 @@
 *
 *
 *      Copyright 2009-2010 Sun Microsystems, Inc.
 *      Portions copyright 2011 ForgeRock AS.
 *      Portions copyright 2011-2013 ForgeRock AS.
 */
package com.forgerock.opendj.ldap;
@@ -66,12 +66,9 @@
        return sb.toString();
    }
    /**
     * {@inheritDoc}
     */
    @Override
    protected boolean isCancelable() {
        return !request.getOID().equals(StartTLSExtendedRequest.OID);
    boolean isBindOrStartTLS() {
        return request.getOID().equals(StartTLSExtendedRequest.OID);
    }
    R decodeResult(final ExtendedResult result, final DecodeOptions options) throws DecodeException {
opendj-ldap-sdk/src/main/resources/org/forgerock/opendj/ldap/core.properties
@@ -1421,4 +1421,12 @@
HBCF_CONNECTION_CLOSED_BY_CLIENT=Connection closed by client
HBCF_HEARTBEAT_FAILED=Heartbeat failed
HBCF_HEARTBEAT_TIMEOUT=Heartbeat timed out after %d ms
LDAP_CONNECTION_REQUEST_TIMEOUT=The request has failed because no response \
 was received from the server within the %d ms timeout
LDAP_CONNECTION_BIND_OR_START_TLS_REQUEST_TIMEOUT=The bind or StartTLS request \
 has failed because no response was received from the server within the %d ms \
 timeout. The LDAP connection is now in an invalid state and can no longer be used
LDAP_CONNECTION_BIND_OR_START_TLS_CONNECTION_TIMEOUT=The LDAP connection has \
 failed because no bind or StartTLS response was received from the server \
 within the %d ms timeout
opendj-ldap-sdk/src/test/java/org/forgerock/opendj/ldap/LDAPConnectionFactoryTestCase.java
@@ -27,6 +27,7 @@
import static com.forgerock.opendj.util.StaticUtils.closeSilently;
import static org.fest.assertions.Assertions.assertThat;
import static org.fest.assertions.Fail.fail;
import static org.forgerock.opendj.ldap.TestCaseUtils.findFreeSocketAddress;
import static org.forgerock.opendj.ldap.requests.Requests.newSimpleBindRequest;
import static org.mockito.Mockito.*;
@@ -42,6 +43,7 @@
import org.forgerock.opendj.ldap.requests.UnbindRequest;
import org.forgerock.opendj.ldap.responses.BindResult;
import org.forgerock.opendj.ldap.responses.SearchResultEntry;
import org.mockito.ArgumentCaptor;
import org.mockito.invocation.InvocationOnMock;
import org.mockito.stubbing.Answer;
import org.mockito.stubbing.Stubber;
@@ -61,10 +63,8 @@
     * and no other operations can be performed. Therefore, a timeout should
     * cause the connection to become invalid and an appropriate connection
     * event sent. In addition, no abandon request should be sent.
     * <p>
     * This test is failing because the connection remains valid.
     */
    @Test(enabled = false)
    @Test
    public void testClientSideTimeoutForBindRequest() throws Exception {
        final AtomicReference<LDAPClientContext> context = new AtomicReference<LDAPClientContext>();
        final Semaphore latch = new Semaphore(0);
@@ -106,12 +106,17 @@
            // Wait for the request to timeout.
            try {
                future.get(TEST_TIMEOUT, TimeUnit.SECONDS);
                fail("The bind request succeeded unexpectedly");
            } catch (TimeoutResultException e) {
                assertThat(e.getResult().getResultCode()).isEqualTo(ResultCode.CLIENT_SIDE_TIMEOUT);
                verify(handler).handleErrorResult(same(e));
                // The connection should no longer be valid.
                verify(listener).handleConnectionError(eq(false), same(e));
                ArgumentCaptor<ErrorResultException> capturedError =
                        ArgumentCaptor.forClass(ErrorResultException.class);
                verify(listener).handleConnectionError(eq(false), capturedError.capture());
                assertThat(capturedError.getValue().getResult().getResultCode()).isEqualTo(
                        ResultCode.CLIENT_SIDE_TIMEOUT);
                assertThat(connection.isValid()).isFalse();
                connection.close();
@@ -137,14 +142,98 @@
    }
    /**
     * Unit test for OPENDJ-1247: as per previous test, except this time verify
     * that the connection failure removes the connection from a connection
     * pool.
     */
    @Test
    public void testClientSideTimeoutForBindRequestInConnectionPool() throws Exception {
        final AtomicReference<LDAPClientContext> context = new AtomicReference<LDAPClientContext>();
        final Semaphore latch = new Semaphore(0);
        // The server connection should receive a bind, but no abandon request.
        final ServerConnection<Integer> serverConnection = mock(ServerConnection.class);
        release(latch).when(serverConnection).handleBind(any(Integer.class), anyInt(),
                any(BindRequest.class), any(IntermediateResponseHandler.class),
                any(ResultHandler.class));
        release(latch).when(serverConnection).handleConnectionClosed(any(Integer.class),
                any(UnbindRequest.class));
        final LDAPListener server = createServer(latch, context, serverConnection);
        final ConnectionFactory factory =
                Connections.newFixedConnectionPool(
                        new LDAPConnectionFactory(server.getSocketAddress(), new LDAPOptions()
                                .setTimeout(1, TimeUnit.MILLISECONDS)), 10);
        Connection connection = null;
        try {
            // Get pooled connection to the server.
            connection = factory.getConnection();
            // Wait for the server to accept the connection.
            assertThat(latch.tryAcquire(TEST_TIMEOUT, TimeUnit.SECONDS)).isTrue();
            /*
             * Sanity check: close the connection and reopen. There should be no
             * interactions with the server due to the pool.
             */
            connection.close();
            connection = factory.getConnection();
            verifyNoMoreInteractions(serverConnection);
            // Now bind with timeout.
            final ResultHandler<BindResult> handler = mock(ResultHandler.class);
            final FutureResult<BindResult> future =
                    connection.bindAsync(newSimpleBindRequest(), null, handler);
            // Wait for the server to receive the bind request.
            assertThat(latch.tryAcquire(TEST_TIMEOUT, TimeUnit.SECONDS)).isTrue();
            // Wait for the request to timeout.
            try {
                future.get(TEST_TIMEOUT, TimeUnit.SECONDS);
                fail("The bind request succeeded unexpectedly");
            } catch (TimeoutResultException e) {
                assertThat(e.getResult().getResultCode()).isEqualTo(ResultCode.CLIENT_SIDE_TIMEOUT);
                verify(handler).handleErrorResult(same(e));
                // The connection should no longer be valid.
                assertThat(connection.isValid()).isFalse();
                connection.close();
                // Wait for the server to receive the close request.
                assertThat(latch.tryAcquire(TEST_TIMEOUT, TimeUnit.SECONDS)).isTrue();
                /*
                 * Check that the only interactions were the bind and the close
                 * and specifically there was no abandon request.
                 */
                verify(serverConnection).handleBind(any(Integer.class), eq(3),
                        any(BindRequest.class), any(IntermediateResponseHandler.class),
                        any(ResultHandler.class));
                verify(serverConnection).handleConnectionClosed(any(Integer.class),
                        any(UnbindRequest.class));
                verifyNoMoreInteractions(serverConnection);
                // Now get another connection. This time we should reconnect to the server.
                connection = factory.getConnection();
                // Wait for the server to accept the connection.
                assertThat(latch.tryAcquire(TEST_TIMEOUT, TimeUnit.SECONDS)).isTrue();
            }
        } finally {
            closeSilently(connection);
            factory.close();
            server.close();
        }
    }
    /**
     * Unit test for OPENDJ-1247: a locally timed out request which is not a
     * bind or startTLS should result in a client side timeout error, but the
     * connection should remain valid. In addition, no abandon request should be
     * sent.
     * <p>
     * This test is failing because no abandon request is received.
     */
    @Test(enabled = false)
    @Test
    public void testClientSideTimeoutForSearchRequest() throws Exception {
        final AtomicReference<LDAPClientContext> context = new AtomicReference<LDAPClientContext>();
        final Semaphore latch = new Semaphore(0);
@@ -186,6 +275,7 @@
            // Wait for the request to timeout.
            try {
                future.get(TEST_TIMEOUT, TimeUnit.SECONDS);
                fail("The search request succeeded unexpectedly");
            } catch (TimeoutResultException e) {
                assertThat(e.getResult().getResultCode()).isEqualTo(ResultCode.CLIENT_SIDE_TIMEOUT);
                verify(handler).handleErrorResult(same(e));