CR-7943 Create TestTimer interface for implementing loop until condition

Jean-Noël Rouvignac

31.46.2015 a42df31317a16ad3f6adfb624347883c93dbd68b

CR-7943 Create TestTimer interface for implementing loop until condition

Added TestTimer interface to abstract loops replaying test conditions until they become true.

TestTimer.java: ADDED

TasksTestCase.java, ChangelogBackendTestCase.java:
Used TestTimer to replace sleeps and counters.

 opendj-server-legacy/src/test/java/org/opends/server/backends/ChangelogBackendTestCase.java

@@ -25,6 +25,8 @@
 */
package org.opends.server.backends;

import static java.util.concurrent.TimeUnit.*;

import static org.assertj.core.api.Assertions.*;
import static org.forgerock.opendj.ldap.ResultCode.*;
import static org.opends.messages.ReplicationMessages.*;
@@ -35,6 +37,7 @@
import static org.opends.server.util.CollectionUtils.*;
import static org.opends.server.util.ServerConstants.*;
import static org.opends.server.util.StaticUtils.*;
import static org.opends.server.util.TestTimer.*;
import static org.testng.Assert.*;

import java.io.ByteArrayOutputStream;
@@ -47,8 +50,8 @@
import java.util.Map;
import java.util.Set;
import java.util.SortedSet;
import java.util.concurrent.Callable;

import org.assertj.core.api.Assertions;
import org.forgerock.i18n.slf4j.LocalizedLogger;
import org.forgerock.opendj.ldap.ByteString;
import org.forgerock.opendj.ldap.ModificationType;
@@ -106,6 +109,7 @@
import org.opends.server.types.SearchFilter;
import org.opends.server.types.SearchResultEntry;
import org.opends.server.util.LDIFWriter;
import org.opends.server.util.TestTimer;
import org.opends.server.util.TimeThread;
import org.opends.server.workflowelement.localbackend.LocalBackendModifyDNOperation;
import org.testng.annotations.AfterClass;
@@ -473,32 +477,28 @@
    }
  }

  private void isOldestCSNForReplica(DN baseDN, CSN csn) throws Exception
  private void isOldestCSNForReplica(final DN baseDN, final CSN csn) throws Exception
  {
    AssertionError ex = null;
    int cnt = 0;
    while (cnt < 30)
    TestTimer timer = new TestTimer.Builder()
      .maxSleep(3, SECONDS)
      .sleepTimes(100, MILLISECONDS)
      .toTimer();
    timer.repeatUntilSuccess(new Callable<Void>()
    {
      cnt++;
      final ReplicationDomainDB domainDB = replicationServer.getChangelogDB().getReplicationDomainDB();
      CursorOptions options = new CursorOptions(GREATER_THAN_OR_EQUAL_TO_KEY, ON_MATCHING_KEY);
      try (DBCursor<UpdateMsg> cursor = domainDB.getCursorFrom(baseDN, csn.getServerId(), csn, options))
      @Override
      public Void call() throws Exception
      {
        assertTrue(cursor.next(),
            "Expected to find at least one change in replicaDB(" + baseDN + " " + csn.getServerId() + ")");
        assertEquals(cursor.getRecord().getCSN(), csn);
        return;
        final ReplicationDomainDB domainDB = replicationServer.getChangelogDB().getReplicationDomainDB();
        CursorOptions options = new CursorOptions(GREATER_THAN_OR_EQUAL_TO_KEY, ON_MATCHING_KEY);
        try (DBCursor<UpdateMsg> cursor = domainDB.getCursorFrom(baseDN, csn.getServerId(), csn, options))
        {
          assertTrue(cursor.next(), "Expected to find at least one change in replicaDB(" + baseDN + " "
              + csn.getServerId() + ")");
          assertEquals(cursor.getRecord().getCSN(), csn);
          return END_RUN;
        }
      }
      catch (AssertionError e)
      {
        ex = e;
      }
      Thread.sleep(100);
    }
    if (ex != null)
    {
      throw ex;
    }
    });
  }

  @Test(enabled=true, dependsOnMethods = { "searchInCookieModeOnTwoSuffixes" })
@@ -787,7 +787,7 @@
        newHashSet("firstchangenumber", "lastchangenumber", "changelog", "lastExternalChangelogCookie");

    InternalSearchOperation searchOp = searchDNWithBaseScope(DN_OTEST, attributes);
    waitForSearchOpResult(searchOp, ResultCode.SUCCESS);
    waitForSearchOpResult(searchOp, SUCCESS);

    final List<SearchResultEntry> entries = searchOp.getSearchEntries();
    assertThat(entries).hasSize(1);
@@ -846,12 +846,16 @@
  }

  private List<SearchResultEntry> assertChangelogAttributesInRootDSE(
      int expectedFirstChangeNumber, int expectedLastChangeNumber) throws Exception
      final int expectedFirstChangeNumber, final int expectedLastChangeNumber) throws Exception
  {
    AssertionError error = null;
    for (int count = 0 ; count < 30; count++)
    TestTimer timer = new TestTimer.Builder()
      .maxSleep(3, SECONDS)
      .sleepTimes(100, MILLISECONDS)
      .toTimer();
    return timer.repeatUntilSuccess(new Callable<List<SearchResultEntry>>()
    {
      try
      @Override
      public List<SearchResultEntry> call() throws Exception
      {
        final Set<String> attributes = new LinkedHashSet<>();
        if (expectedFirstChangeNumber > 0)
@@ -876,15 +880,7 @@
        assertNotNull(getAttributeValue(entry, "lastExternalChangelogCookie"));
        return entries;
      }
      catch (AssertionError ae)
      {
        // try again to see if changes have been persisted
        error = ae;
      }
      Thread.sleep(100);
    }
    assertNotNull(error);
    throw error;
    });
  }

  private String readLastCookieFromRootDSE() throws Exception
@@ -905,40 +901,42 @@
    return cookie;
  }

  private String assertLastCookieIsEqualTo(String expectedLastCookie) throws Exception
  private String assertLastCookieIsEqualTo(final String expectedLastCookie) throws Exception
  {
    String lastCookie = null;
    int count = 0;
    while (count < 100)
    TestTimer timer = new TestTimer.Builder()
      .maxSleep(1, SECONDS)
      .sleepTimes(10, MILLISECONDS)
      .toTimer();
    return timer.repeatUntilSuccess(new Callable<String>()
    {
      lastCookie = readLastCookieFromRootDSE();
      if (lastCookie.equals(expectedLastCookie))
      @Override
      public String call() throws Exception
      {
        final String lastCookie = readLastCookieFromRootDSE();
        assertThat(lastCookie).isEqualTo(expectedLastCookie);
        return lastCookie;
      }
      count++;
      Thread.sleep(10);
    }
    Assertions.fail("Expected last cookie to be equal to <" + expectedLastCookie + "> but found <" + lastCookie + ">");
    return null;// dead code
    });
  }

  private String assertLastCookieDifferentThanLastValue(final String notExpectedLastCookie) throws Exception
  {
    int count = 0;
    while (count < 100)
    TestTimer timer = new TestTimer.Builder()
      .maxSleep(1, SECONDS)
      .sleepTimes(10, MILLISECONDS)
      .toTimer();
    return timer.repeatUntilSuccess(new Callable<String>()
    {
      final String lastCookie = readLastCookieFromRootDSE();
      if (!lastCookie.equals(notExpectedLastCookie))
      @Override
      public String call() throws Exception
      {
        final String lastCookie = readLastCookieFromRootDSE();
        assertThat(lastCookie)
          .as("Expected last cookie to be updated, but it always stayed at value '" + notExpectedLastCookie + "'")
          .isNotEqualTo(notExpectedLastCookie);
        return lastCookie;
      }
      count++;
      Thread.sleep(10);
    }
    Assertions.fail("Expected last cookie should have been updated,"
        + " but it always stayed at value '" + notExpectedLastCookie + "'");
    return null;// dead code
    });
  }

  private String readCookieFromNthEntry(List<SearchResultEntry> entries, int i)
@@ -950,7 +948,8 @@
  private String assertEntriesContainsCSNsAndReadLastCookie(String test, List<SearchResultEntry> entries,
      LDIFWriter ldifWriter, CSN... csns) throws Exception
  {
    assertThat(getCSNsFromEntries(entries)).containsExactly(csns);
    // TODO JNR Should the order be guaranteed?
    assertThat(getCSNsFromEntries(entries)).containsOnly(csns);
    debugAndWriteEntries(ldifWriter, entries, test);
    return readCookieFromNthEntry(entries, csns.length - 1);
  }
@@ -1114,18 +1113,23 @@
        .addAttribute("*", "+"); // all user and operational attributes
  }

  private InternalSearchOperation searchChangelog(SearchRequest request, int expectedNbEntries,
  private InternalSearchOperation searchChangelog(final SearchRequest request, final int expectedNbEntries,
      ResultCode expectedResultCode, String testName) throws Exception
  {
    InternalSearchOperation searchOp = null;
    int count = 0;
    do
    TestTimer timer = new TestTimer.Builder()
      .maxSleep(5, SECONDS)
      .sleepTimes(10, MILLISECONDS)
      .toTimer();
    InternalSearchOperation searchOp = timer.repeatUntilSuccess(new Callable<InternalSearchOperation>()
    {
      Thread.sleep(10);
      searchOp = connection.processSearch(request);
      count++;
    }
    while (count < 500 && searchOp.getSearchEntries().size() != expectedNbEntries);
      @Override
      public InternalSearchOperation call() throws Exception
      {
        InternalSearchOperation searchOp = connection.processSearch(request);
        assertThat(searchOp.getSearchEntries()).hasSize(expectedNbEntries);
        return searchOp;
      }
    });

    final List<SearchResultEntry> entries = searchOp.getSearchEntries();
    assertThat(entries).hasSize(expectedNbEntries);
@@ -1225,18 +1229,21 @@
  }

  /** TODO : share this code with other classes ? */
  private void waitForSearchOpResult(Operation operation, ResultCode expectedResult) throws Exception
  private void waitForSearchOpResult(final Operation operation, final ResultCode expectedResult) throws Exception
  {
    int i = 0;
    while (operation.getResultCode() == ResultCode.UNDEFINED || operation.getResultCode() != expectedResult)
    TestTimer timer = new TestTimer.Builder()
      .maxSleep(500, MILLISECONDS)
      .sleepTimes(50, MILLISECONDS)
      .toTimer();
    timer.repeatUntilSuccess(new Callable<Void>()
    {
      Thread.sleep(50);
      i++;
      if (i > 10)
      @Override
      public Void call() throws Exception
      {
        assertEquals(operation.getResultCode(), expectedResult, operation.getErrorMessage().toString());
        return END_RUN;
      }
    }
    });
  }

  /** Verify that no entry contains the ChangeLogCookie control. */

 opendj-server-legacy/src/test/java/org/opends/server/tasks/TasksTestCase.java

@@ -22,11 +22,12 @@
 *
 *
 *      Copyright 2006-2008 Sun Microsystems, Inc.
 *      Portions Copyright 2014 ForgeRock AS
 *      Portions Copyright 2014-2015 ForgeRock AS
 */
package org.opends.server.tasks;

import java.util.Set;
import java.util.concurrent.Callable;

import org.forgerock.opendj.ldap.ResultCode;
import org.forgerock.opendj.ldap.SearchScope;
@@ -36,14 +37,16 @@
import org.opends.server.backends.task.TaskState;
import org.opends.server.core.AddOperation;
import org.opends.server.core.DirectoryServer;
import org.opends.server.protocols.internal.InternalClientConnection;
import org.opends.server.protocols.internal.InternalSearchOperation;
import org.opends.server.protocols.internal.SearchRequest;
import org.opends.server.types.AttributeParser;
import org.opends.server.types.DN;
import org.opends.server.types.Entry;
import org.opends.server.util.TestTimer;
import org.testng.annotations.Test;

import static java.util.concurrent.TimeUnit.*;

import static org.opends.server.config.ConfigConstants.*;
import static org.opends.server.protocols.internal.InternalClientConnection.*;
import static org.opends.server.protocols.internal.Requests.*;
@@ -59,39 +62,18 @@
   * Add a task definition and check that it completes with the expected state.
   * @param taskEntry The task entry.
   * @param expectedState The expected completion state of the task.
   * @param timeout The number of seconds to wait for the task to complete.
   * @param timeoutInSec The number of seconds to wait for the task to complete.
   * @throws Exception If the test fails.
   */
  protected void testTask(Entry taskEntry, TaskState expectedState, int timeout)
       throws Exception
  protected void testTask(Entry taskEntry, TaskState expectedState, int timeoutInSec) throws Exception
  {
    InternalClientConnection connection = getRootConnection();

    // Add the task.
    AddOperation addOperation = connection.processAdd(taskEntry);
    AddOperation addOperation = getRootConnection().processAdd(taskEntry);
    assertEquals(addOperation.getResultCode(), ResultCode.SUCCESS,
                 "Add of the task definition was not successful");

    // Wait until the task completes.
    final SearchRequest request = newSearchRequest(taskEntry.getName(), SearchScope.BASE_OBJECT);
    Entry resultEntry = null;
    String completionTime = null;
    long startMillisecs = System.currentTimeMillis();
    boolean timedOut;
    do
    {
      Thread.sleep(100);
      InternalSearchOperation searchOperation = connection.processSearch(request);
      resultEntry = searchOperation.getSearchEntries().getFirst();
      completionTime = parseAttribute(resultEntry, ATTR_TASK_COMPLETION_TIME).asString();
      timedOut = System.currentTimeMillis() - startMillisecs > 1000 * timeout;
    }
    while (completionTime == null && !timedOut);

    assertNotNull(completionTime, "The task had not completed after " + timeout + " seconds.\n"
        + "resultEntry=[" + resultEntry + "]");

    // Check that the task state is as expected.
    Entry resultEntry = getCompletedTaskEntry(taskEntry.getName(), timeoutInSec);
    String stateString = parseAttribute(resultEntry, ATTR_TASK_STATE).asString();
    TaskState taskState = TaskState.fromString(stateString);
    assertEquals(taskState, expectedState,
@@ -99,12 +81,33 @@

    // Check that the task contains some log messages.
    Set<String> logMessages = parseAttribute(resultEntry, ATTR_TASK_LOG_MESSAGES).asSetOfString();
    if (taskState != TaskState.COMPLETED_SUCCESSFULLY && logMessages.isEmpty())
    {
      fail("No log messages were written to the task entry on a failed task.\n"
    assertTrue(taskState == TaskState.COMPLETED_SUCCESSFULLY || !logMessages.isEmpty(),
        "No log messages were written to the task entry on a failed task.\n"
          + "taskState=" + taskState
          + "logMessages size=" + logMessages.size() + " and content=[" + logMessages + "]");
    }
  }

  private Entry getCompletedTaskEntry(DN name, final int timeoutInSec) throws Exception
  {
    final SearchRequest request = newSearchRequest(name, SearchScope.BASE_OBJECT);

    TestTimer timer = new TestTimer.Builder()
      .maxSleep(timeoutInSec, SECONDS)
      .sleepTimes(100, MILLISECONDS)
      .toTimer();
    return timer.repeatUntilSuccess(new Callable<Entry>()
    {
      @Override
      public Entry call()
      {
        InternalSearchOperation searchOperation = getRootConnection().processSearch(request);
        Entry resultEntry = searchOperation.getSearchEntries().getFirst();
        String completionTime = parseAttribute(resultEntry, ATTR_TASK_COMPLETION_TIME).asString();
        assertNotNull(completionTime,
            "The task had not completed after " + timeoutInSec + " seconds.\nresultEntry=[" + resultEntry + "]");
        return resultEntry;
      }
    });
  }

  private AttributeParser parseAttribute(Entry resultEntry, String attrName)
@@ -121,23 +124,24 @@
   * @throws  Exception  If an unexpected problem occurs.
   */
  @Test(enabled=false) // This isn't a test method, but TestNG thinks it is.
  public static Task getTask(DN taskEntryDN) throws Exception
  public static Task getTask(final DN taskEntryDN) throws Exception
  {
    TaskBackend taskBackend =
         (TaskBackend) DirectoryServer.getBackend(DN.valueOf("cn=tasks"));
    Task task = taskBackend.getScheduledTask(taskEntryDN);
    if (task == null)
    {
      long stopWaitingTime = System.currentTimeMillis() + 10000L;
      while (task == null && System.currentTimeMillis() < stopWaitingTime)
      {
        Thread.sleep(10);
        task = taskBackend.getScheduledTask(taskEntryDN);
      }
    }
    final TaskBackend taskBackend = (TaskBackend) DirectoryServer.getBackend(DN.valueOf("cn=tasks"));

    assertNotNull(task, "There is no such task " + taskEntryDN);
    return task;
    TestTimer timer = new TestTimer.Builder()
      .maxSleep(10, SECONDS)
      .sleepTimes(10, MILLISECONDS)
      .toTimer();
    return timer.repeatUntilSuccess(new Callable<Task>()
    {
      @Override
      public Task call() throws Exception
      {
        Task task = taskBackend.getScheduledTask(taskEntryDN);
        assertNotNull("There is no such task " + taskEntryDN);
        return task;
      }
    });
  }


@@ -153,21 +157,23 @@
   * @throws  Exception  If an unexpected problem occurs.
   */
  @Test(enabled=false) // This isn't a test method, but TestNG thinks it is.
  public static Task getCompletedTask(DN taskEntryDN) throws Exception
  public static Task getCompletedTask(final DN taskEntryDN) throws Exception
  {
    Task task = getTask(taskEntryDN);
    final Task task = getTask(taskEntryDN);

    if (! TaskState.isDone(task.getTaskState()))
    TestTimer timer = new TestTimer.Builder()
      .maxSleep(20, SECONDS)
      .sleepTimes(10, MILLISECONDS)
      .toTimer();
    return timer.repeatUntilSuccess(new Callable<Task>()
    {
      long stopWaitingTime = System.currentTimeMillis() + 20000L;
      while (! TaskState.isDone(task.getTaskState()) &&
             System.currentTimeMillis() < stopWaitingTime)
      @Override
      public Task call() throws Exception
      {
        Thread.sleep(10);
        assertTrue(TaskState.isDone(task.getTaskState()),
            "Task " + taskEntryDN + " did not complete in a timely manner.");
        return task;
      }
    }

    assertTrue(TaskState.isDone(task.getTaskState()), "Task " + taskEntryDN + " did not complete in a timely manner.");
    return task;
    });
  }
}

 opendj-server-legacy/src/test/java/org/opends/server/util/TestTimer.java

New file
@@ -0,0 +1,200 @@
/*
 * CDDL HEADER START
 *
 * The contents of this file are subject to the terms of the
 * Common Development and Distribution License, Version 1.0 only
 * (the "License").  You may not use this file except in compliance
 * with the License.
 *
 * You can obtain a copy of the license at legal-notices/CDDLv1_0.txt
 * or http://forgerock.org/license/CDDLv1.0.html.
 * See the License for the specific language governing permissions
 * and limitations under the License.
 *
 * When distributing Covered Code, include this CDDL HEADER in each
 * file and include the License file at legal-notices/CDDLv1_0.txt.
 * If applicable, add the following below this CDDL HEADER, with the
 * fields enclosed by brackets "[]" replaced with your own identifying
 * information:
 *      Portions Copyright [yyyy] [name of copyright owner]
 *
 * CDDL HEADER END
 *
 *      Copyright 2015 ForgeRock AS
 */
package org.opends.server.util;

import java.util.concurrent.Callable;
import java.util.concurrent.TimeUnit;

import org.forgerock.util.Reject;

/**
 * Timer useful for testing: it helps to write loops that repeatedly runs code until some condition
 * is met.
 */
public interface TestTimer
{
  /**
   * Constant that can be used at the end of {@code Callable<Void>.call()} to better explicit this
   * is the end of the method.
   */
  Void END_RUN = null;

  /**
   * Repeatedly call the supplied callable (respecting a sleep interval) until:
   * <ul>
   * <li>it returns,</li>
   * <li>it throws an exception other than {@link AssertionError},</li>
   * <li>the current timer times out.</li>
   * </ul>
   * If the current timer times out, then it will:
   * <ul>
   * <li>either rethrow an {@link AssertionError} thrown by the callable,</li>
   * <li>or return {@code null}.</li>
   * </ul>
   * <p>
   * Note: The test code in the callable can be written as any test code outside a callable. In
   * particular, asserts can and should be used inside the {@link Callable#call()}.
   *
   * @param callable
   *          the callable to repeat until success
   * @param <R>
   *          The return type of the callable
   * @return the value returned by the callable (may be {@code null}), or {@code null} if the timer
   *         times out
   * @throws Exception
   *           The exception thrown by the provided callable
   * @throws InterruptedException
   *           If the thread is interrupted while sleeping
   */
  <R> R repeatUntilSuccess(Callable<R> callable) throws Exception, InterruptedException;

  /** Builder for a {@link TestTimer}. */
  public static final class Builder
  {
    private long maxSleepTimeInMillis;
    private long sleepTimes;

    /**
     * Configures the maximum sleep duration.
     *
     * @param time
     *          the duration
     * @param unit
     *          the time unit for the duration
     * @return this builder
     */
    public Builder maxSleep(long time, TimeUnit unit)
    {
      Reject.ifFalse(time > 0, "time must be positive");
      this.maxSleepTimeInMillis = unit.toMillis(time);
      return this;
    }

    /**
     * Configures the duration for sleep times.
     *
     * @param time
     *          the duration
     * @param unit
     *          the time unit for the duration
     * @return this builder
     */
    public Builder sleepTimes(long time, TimeUnit unit)
    {
      Reject.ifFalse(time > 0, "time must be positive");
      this.sleepTimes = unit.toMillis(time);
      return this;
    }

    /**
     * Creates a new timer and start it.
     *
     * @return a new timer
     */
    public TestTimer toTimer()
    {
      return new SteppingTimer(this);
    }
  }

  /** A {@link TestTimer} that sleeps in steps and sleeps at maximum {@code nbSteps * sleepTimes}. */
  public static class SteppingTimer implements TestTimer
  {
    private final long sleepTime;
    private final long totalNbSteps;
    private long nbStepsRemaining;
    private boolean started;

    private SteppingTimer(Builder builder)
    {
      this.sleepTime = builder.sleepTimes;
      this.totalNbSteps = sleepTime > 0 ? builder.maxSleepTimeInMillis / sleepTime : 0;
      this.nbStepsRemaining = totalNbSteps;
    }

    private SteppingTimer startTimer()
    {
      started = true;
      return this;
    }

    /**
     * Returns whether the timer has reached the timeout. This method may block by sleeping.
     *
     * @return {@code true} if the timer has reached the timeout, {@code false} otherwise
     * @throws InterruptedException if the thread has been interrupted
     */
    private boolean hasTimedOut() throws InterruptedException
    {
      final boolean done = hasTimedOutNoSleep();
      if (!done)
      {
        Thread.sleep(sleepTime);
      }
      return done;
    }

    /**
     * Returns whether the timer has reached the timeout, without sleep.
     *
     * @return {@code true} if the timer has reached the timeout, {@code false} otherwise
     */
    private boolean hasTimedOutNoSleep()
    {
      Reject.ifTrue(!started, "start() method should have been called first");
      return nbStepsRemaining-- <= 0;
    }

    @Override
    public <R> R repeatUntilSuccess(Callable<R> callable) throws Exception, InterruptedException
    {
      startTimer();
      do
      {
        try
        {
          return callable.call();
        }
        catch (AssertionError e)
        {
          if (hasTimedOutNoSleep())
          {
            throw e;
          }
        }
      }
      while (!hasTimedOut());
      return null;
    }

    @Override
    public String toString()
    {
      return totalNbSteps * sleepTime + " ms max sleep time"
          + " (" + totalNbSteps + " steps x " + sleepTime + " ms)"
          + ", remaining = " + nbStepsRemaining + " steps";
    }
  }
}