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

Valery Kharseko
yesterday c4a6057b8f4998a81bd60b1e690702ac8b821a62
opendj-server-legacy/src/main/java/org/opends/server/backends/pdb/PDBStorage.java
@@ -105,27 +105,6 @@
  private static final int IMPORT_DB_CACHE_SIZE = 32 * MB;
  /**
   * Number of attempts a {@link WriteableStorageImpl#write} makes before it propagates the conflict to the caller.
   * <p>
   * It is a budget of attempts and not of time, so it is only ever reached by the conflicts that report quickly.
   * PersistIt reports a write-write conflict only once it has waited on it, up to
   * {@code SharedResource.DEFAULT_MAX_WAIT_TIME} - a minute, which this backend never lowers - so a conflict slower
   * to report than {@link #MAX_RETRY_WINDOW_NANOS} spends the whole window inside its first attempt, is granted the
   * single replay that window's exemption guarantees, and gives up on the window after two attempts rather than
   * after this many.
   */
  static final int MAX_RETRIES = 10;
  /**
   * Wall-clock budget the replays of a {@link WriteableStorageImpl#write} may spend, in nanoseconds. It is checked
   * between attempts, so an attempt already running is never interrupted, and never before one replay has been
   * made: the loop returns after at most this window plus two attempts. It bounds the conflicts that are slow to
   * report, which {@link #MAX_RETRIES} alone does not - an operation whose own work takes seconds would otherwise
   * multiply that wait by the attempt count.
   */
  static final long MAX_RETRY_WINDOW_NANOS = 10L * 1000L * 1000L * 1000L; //10 s
  /**
   * Upper bound of the random delay before the second attempt, in milliseconds; it doubles with every attempt. This
   * is the bound of the flat sleep this loop took before it was bounded, so the first replay is delayed exactly as
   * it was and only the later ones back off.
@@ -135,6 +114,10 @@
  /** Upper bound the doubled delay is capped at, in milliseconds. */
  private static final double MAX_SLEEP_ON_RETRY_MS = 1000.0;
  /** Name of the property which bounds the replays of a {@link WriteableStorageImpl#write}, for the reports of it. */
  private static final String RETRY_TIME_LIMIT_PROPERTY =
      PDBBackendCfgDefn.getInstance().getDBTxnRetryTimeLimitPropertyDefinition().getName();
  private static final String VOLUME_NAME = "dj";
  private static final String JOURNAL_NAME = VOLUME_NAME + "_journal";
  /** The buffer / page size used by the PersistIt storage. */
@@ -671,7 +654,10 @@
    {
      final Transaction txn = db.getTransaction();
      final long startedAt = System.nanoTime();
      final long giveUpAt = startedAt + retryWindowNanos;
      //read once, so that a change of the property applies from the next write on rather than to one in flight;
      //0 replays for as long as the conflict lasts
      final long retryTimeLimitMs = config.getDBTxnRetryTimeLimit();
      final long giveUpAt = startedAt + TimeUnit.MILLISECONDS.toNanos(retryTimeLimitMs);
      for (int attempt = 1;; attempt++)
      {
        final RollbackException conflict;
@@ -705,24 +691,26 @@
        // decided and slept for outside the try statement: the sleep used to run before the finally ended the
        // rolled back transaction, holding it open for the whole backoff and lengthening the window every other
        // writer collides with
        //Bounded by time alone, and not by a count of attempts: a rollback is how persistit resolves two
        //transactions writing the same key - it waits for the other one to end and rolls this one back if that
        //one committed - so under concurrent writes to a hot key, such as an index key shared by entries below
        //the index entry limit, a healthy write loses several of these races in a row (#1149)
        //System.nanoTime() - giveUpAt is the overflow safe form of the comparison, and attempt > 1 keeps the
        //window from ending the loop before a single replay: persistit reports a write-write conflict only once
        //limit from ending the loop before a single replay: persistit reports a write-write conflict only once
        //it has waited on it, up to SharedResource.DEFAULT_MAX_WAIT_TIME - a minute, which this backend never
        //lowers - so one attempt can outlast the window on its own, and it is the attempt after that one which
        //lowers - so one attempt can outlast the limit on its own, and it is the attempt after that one which
        //is likeliest to succeed, the transaction that blocked it having just finished
        //one clock sample for both, so that the elapsed time reported is the one the give up was decided on
        final long now = System.nanoTime();
        final boolean capSpent = attempt >= maxRetries;
        if (capSpent || (attempt > 1 && now - giveUpAt >= 0))
        if (retryTimeLimitMs > 0 && attempt > 1 && now - giveUpAt >= 0)
        {
          final long elapsedMs = TimeUnit.NANOSECONDS.toMillis(now - startedAt);
          //which of the two bounds was spent, so that the config change paths - which report this as the trailing
          //cause of a message of their own - say whether raising the attempts or the window is what would have helped
          final String boundSpent = capSpent ? "attempt cap" : "retry window";
          //names the property, so that the config change paths - which report this as the trailing cause of a
          //message of their own - say what would have helped
          final StorageRuntimeException spent = new StorageRuntimeException(
              "pdb: backend '" + config.getBackendId() + "' did not apply the transaction after " + attempt
                  + " attempts in " + elapsedMs + " ms, the " + boundSpent + " being spent; the last conflict was "
                  + conflict);
                  + " attempts in " + elapsedMs + " ms, the " + RETRY_TIME_LIMIT_PROPERTY + " of " + retryTimeLimitMs
                  + " ms being spent; the last conflict was " + conflict);
          // the conflict is suppressed rather than made the cause, because a cause is what every caller strips
          // this message off with: write(WriteOperation) below unwraps a StorageRuntimeException that carries one
          // and throws the cause in its place, and EntryContainer.throwAllowedExceptionTypes:1121 rethrows a
@@ -732,17 +720,17 @@
          spent.addSuppressed(conflict);
          //warned once, at exhaustion only, unlike JDBCStorage which warns on every replay: a conflict is routine
          //on the ordinary add and modify path of this engine and a line per replay would flood the log. It names
          //the bound that was spent for the same reason the exception does, and it is the only rendering that can
          //carry the stack of the conflict: stackTraceToSingleLineString, the form the config change paths report
          //this exception with, walks the causes and never prints a suppressed exception
          //the property that was spent for the same reason the exception does, and it is the only rendering that
          //can carry the stack of the conflict: stackTraceToSingleLineString, the form the config change paths
          //report this exception with, walks the causes and never prints a suppressed exception
          logger.warn(LocalizableMessage.raw("pdb: giving up on the transaction of backend '%s' after %d attempts"
              + " in %d ms, the %s being spent: %s", config.getBackendId(), attempt, elapsedMs, boundSpent,
              stackTraceToSingleLineString(conflict)));
              + " in %d ms, the %s of %d ms being spent: %s", config.getBackendId(), attempt, elapsedMs,
              RETRY_TIME_LIMIT_PROPERTY, retryTimeLimitMs, stackTraceToSingleLineString(conflict)));
          throw spent;
        }
        if (logger.isTraceEnabled())
        {
          logger.trace("pdb: replaying the transaction after %s, attempt %d of %d", conflict, attempt, maxRetries);
          logger.trace("pdb: replaying the transaction after %s, attempt %d", conflict, attempt);
        }
        try
        {
@@ -1030,10 +1018,6 @@
  private long configuredCacheSize;
  private long reservedCacheSize;
  private StorageStatus storageStatus = StorageStatus.working();
  /** Attempt bound of a {@link WriteableStorageImpl#write}, {@link #MAX_RETRIES} outside the tests. */
  private final int maxRetries;
  /** Wall-clock bound of a {@link WriteableStorageImpl#write}, {@link #MAX_RETRY_WINDOW_NANOS} outside the tests. */
  private final long retryWindowNanos;
  /**
   * Creates a new persistit storage with the provided configuration.
@@ -1047,34 +1031,7 @@
  // FIXME: should be package private once importer is decoupled.
  public PDBStorage(final PDBBackendCfg cfg, ServerContext serverContext) throws ConfigException
  {
    this(cfg, serverContext, MAX_RETRIES, MAX_RETRY_WINDOW_NANOS);
  }
  /**
   * Creates a new persistit storage whose replay bounds are the given ones rather than {@link #MAX_RETRIES} and
   * {@link #MAX_RETRY_WINDOW_NANOS}.
   * <p>
   * Only a test builds one of these, and it does so to stop the two bounds racing each other: with the shipped
   * values a run of replays spends a random share of the window on backoff alone, so a test of the attempt cap
   * can be ended by the window on a loaded machine, and a test of the window has to spend seconds of build time
   * to reach it.
   *
   * @param cfg
   *          The configuration.
   * @param serverContext
   *          This server instance context
   * @param maxRetries
   *          Number of attempts a write makes before it propagates the conflict to the caller.
   * @param retryWindowNanos
   *          Wall-clock budget the replays of a write may spend, in nanoseconds.
   * @throws ConfigException if memory cannot be reserved
   */
  PDBStorage(final PDBBackendCfg cfg, ServerContext serverContext, int maxRetries, long retryWindowNanos)
      throws ConfigException
  {
    this.serverContext = serverContext;
    this.maxRetries = maxRetries;
    this.retryWindowNanos = retryWindowNanos;
    backendDirectory = getBackendDirectory(cfg);
    runningDirectoryPermissions = cfg.getDBDirectoryPermissions();
    config = cfg;
@@ -1293,15 +1250,17 @@
  /**
   * {@inheritDoc}
   * <p>
   * A transaction the engine rolled back is replayed, bounded twice: by {@link #MAX_RETRIES} attempts and by the
   * {@link #MAX_RETRY_WINDOW_NANOS} wall-clock window, whichever is spent first - except that the window alone
   * never ends the replays before one has been made. It is bounded because the
   * configuration change paths of the pluggable backend hold an entry container's exclusive lock across this
   * method, and every reader of that suffix then waits - untimed and uninterruptibly - until it returns, so a
   * conflict that never clears would park every worker thread of that suffix rather than fail one operation.
   * A transaction the engine rolled back is replayed for as long as the {@code db-txn-retry-time-limit} of the
   * backend allows - without limit when it is 0, its default - except that the limit never ends the replays before
   * one has been made. A rollback is how persistit resolves two transactions writing the same key, so a healthy
   * write under concurrent load can lose several of them in a row: a count of attempts failed such writes (#1149),
   * and the replays are bounded by time alone. Without a limit a write waits for its conflict to clear the way a
   * JE writer waits for a lock. A limit is for the configuration change paths of the pluggable backend, which hold
   * an entry container's exclusive lock across this method: every reader of that suffix then waits - untimed and
   * uninterruptibly - until it returns.
   * <p>
   * Once the bound is spent the conflict is reported as a {@link StorageRuntimeException} naming the backend, the
   * attempts spent, the time they took and which of the two bounds ran out. It carries the conflict as a
   * Once the limit is spent the conflict is reported as a {@link StorageRuntimeException} naming the backend, the
   * attempts spent, the time they took and the property whose value ran out. It carries the conflict as a
   * suppressed exception rather than as its cause: a cause is unwrapped below and thrown in its place, and
   * {@code EntryContainer.throwAllowedExceptionTypes} likewise passes a {@link StorageRuntimeException} through
   * untouched only while it has no cause. Given a cause, both hand the caller a bare RollbackException instead,