[#903] Grant the free replay to the prompt conflicts alone, and keep one wi...

maximthomas

2 days ago 52adad385c178dc231693e90b559d677219251eb

[#903] Grant the free replay to the prompt conflicts alone, and keep one window

The first replay was granted to every conflict, which handed it to the one
class that does not need it. A MySQL lock wait timeout is reported only once
innodb_lock_wait_timeout has elapsed - the engine has already bounded that
wait - so a free replay buys a second wait of the same length, 100 s at the
50 s default where master released the worker after 50 s. Worse, the window
was never consulted for it: the grant returned first, so the 10 s bound could
not fire against the single most expensive replay it was introduced to stop.

The grant now goes to Conflict.PROMPT only, whose preceding wait SQL Server,
Oracle and PostgreSQL all leave unbounded - no window survives it, and
measuring one against it is what left issue #903 with zero replays.
AFTER_LOCK_WAIT is measured against the window from the first attempt, which
is what the class was introduced to do.

With the grant narrowed, the 60 s widening of the prompt window was
compensating for a defect rather than for anything real, and it multiplied by
six how long a conflicted write pins a worker thread - a deadlock storm hits
every worker at once. Reverted to 10 s. That leaves the two window constants
bound to the same literal, a name apiece for one value, so they are collapsed
into RETRY_WINDOW_NANOS and windowOf() is deleted. The Conflict enum survives
and is no longer inert at the documented default: it decides the grant.

Also:

- conflictOf() walks the whole cause chain and keeps the most specific class
  found, so a wrapper carrying a bare class 40 state no longer downgrades the
  AFTER_LOCK_WAIT of the SQLException it wraps.
- isRetryableConflict() is deleted; write() has called replayable() since the
  previous commit and nothing in src/main called the wrapper. Its doc moves
  onto conflictOf().
- The replay warning names the conflict class and both bounds, in ms - whole
  seconds read "0 s" for most of a burst - since the effective cap is usually
  the window and a log naming only MAX_RETRIES said nothing about why an
  operation gave up at attempt 2 of a promised 10.

The line that held the original bug - startedAt read once outside the retry
loop - had no test: replayable() is handed an elapsed time rather than
measuring one, so moving that read inside the loop kept every case green
while restoring an unbounded retry. testWriteDrivesTheRetryLoop drives write()
through a scripted clock over a new nanoTime() seam and pins both lines. The
step size is load-bearing in each direction: at 4 s the run must stop on the
third attempt, which the relocated read turns into ten, and at 12 s only the
grant can produce a second attempt, so removing it stops the run on the first.

Claude-Session: https://claude.ai/code/session_0123YLkjSmyp15GynenKE9vP

 opendj-server-legacy/src/main/java/org/opends/server/backends/jdbc/JDBCStorage.java

@@ -41,6 +41,7 @@
import java.sql.*;
import java.util.*;
import java.util.concurrent.ConcurrentHashMap;
import java.util.concurrent.TimeUnit;

import static org.opends.server.backends.pluggable.spi.StorageUtils.addErrorMessage;
import static org.opends.server.util.StaticUtils.stackTraceToSingleLineString;
@@ -53,28 +54,18 @@
    private static final int MAX_RETRIES = 10;

    /**
     * Wall-clock budget the replays of a {@link #write} may spend on a {@link Conflict#AFTER_LOCK_WAIT} conflict,
     * in nanoseconds. It is checked between attempts, so an attempt already running is never interrupted, and it
     * bounds the replays after the first, which is granted unconditionally: the loop returns after two attempts,
     * or after this window plus one attempt, whichever comes later. It bounds what {@link #MAX_RETRIES} alone does
     * not - MySQL reports a lock wait timeout only after innodb_lock_wait_timeout, 50 s by default and not
     * overridden here, so ten attempts would park a worker thread for eight minutes where two release it after
     * 100 s.
     * Wall-clock budget the replays of a {@link #write} may spend, in nanoseconds, measured from the start of the
     * first attempt. It is checked between attempts, so an attempt already running is never interrupted, and it
     * applies from the first check, with the single exception {@link #replayable(int, long, Throwable, String)}
     * describes: a conflict its engine reports promptly is granted one replay whatever the clock says, because the
     * lock wait that precedes such a conflict is charged to the attempt and is unbounded on three of the four
     * engines here, so no window survives it. It bounds what {@link #MAX_RETRIES} alone does not - MySQL reports a
     * lock wait timeout only after innodb_lock_wait_timeout, 50 s by default and not overridden here, so ten
     * attempts would park a worker thread for eight minutes where one releases it after 50 s. Bounding the attempt
     * itself, with a session lock timeout on the transaction connection, is what would let this window bound the
     * prompt conflicts too; until it lands they cost one attempt more than the window.
     */
    private static final long LOCK_WAIT_RETRY_WINDOW_NANOS = 10L * 1000L * 1000L * 1000L; //10 s

    /**
     * Wall-clock budget the replays of a {@link #write} may spend on a {@link Conflict#PROMPT} conflict, in
     * nanoseconds. Wider, because an attempt ending in a deadlock is not short either, for a reason of its own:
     * detection is prompt, but the victim is charged the lock wait that precedes it, and SQL Server, Oracle and
     * PostgreSQL all leave that wait unbounded - a victim of concurrent writers took some 12 s to be picked in CI,
     * and under the window above the replays that followed the first were disarmed by a wait that belongs to the
     * attempt rather than to them. Widening it is paid for by the caller, which holds a worker thread for up to
     * this window plus one attempt where it held one for ten seconds plus an attempt before - six times as long in
     * the worst case, and still preferable to failing an operation the engine asked to have rerun, with
     * {@link #MAX_RETRIES} capping the attempts made inside it.
     */
    private static final long PROMPT_CONFLICT_RETRY_WINDOW_NANOS = 60L * 1000L * 1000L * 1000L; //60 s
    private static final long RETRY_WINDOW_NANOS = TimeUnit.SECONDS.toNanos(10);

    /** Upper bound of the random delay before the second attempt, in milliseconds; it doubles with every attempt. */
    private static final double BASE_SLEEP_ON_RETRY_MS = 50.0;
@@ -859,17 +850,16 @@
     * exactly that reason; {@link org.opends.server.backends.pdb.PDBStorage#write(WriteOperation)} already does so
     * on the conflict exception of its own engine. The loop is bounded here, unlike PDBStorage: the database may be
     * shared with writers outside this server, so a conflict is not guaranteed to clear and failing the operation is
     * better than never returning. It is bounded twice - by {@link #MAX_RETRIES} attempts and by a wall-clock
     * window - because an attempt is not guaranteed to be short: a conflict an engine reports only after its own
     * lock wait timeout would otherwise multiply that wait by the attempt count. The window is the one the class
     * of the conflict is given - {@link #LOCK_WAIT_RETRY_WINDOW_NANOS} or
     * {@link #PROMPT_CONFLICT_RETRY_WINDOW_NANOS} - because a window shorter than the wait that precedes a conflict
     * does not bound that wait but only leaves the operation with no replay at all; see
     * {@link #replayable(int, long, Throwable, String)}. Either window is checked between attempts, so an attempt
     * already running is never interrupted, and it bounds the replays after the first: a conflicted operation holds
     * its caller for two attempts, or for the window of its class plus one attempt, whichever is later - a minute
     * plus an attempt for a deadlock, and for a MySQL lock wait timeout the two waits of 50 s the engine takes to
     * report it twice.
     * better than never returning. It is bounded twice - by {@link #MAX_RETRIES} attempts and by the
     * {@link #RETRY_WINDOW_NANOS} wall-clock window - because an attempt is not guaranteed to be short: a conflict
     * an engine reports only after its own lock wait timeout would otherwise multiply that wait by the attempt
     * count. The window alone is not enough either, in the other direction: it is shorter than the wait that
     * precedes a conflict the engine reports promptly, so measured against such a conflict it does not bound that
     * wait but only leaves the operation with no replay at all, which is what master did with the deadlock of
     * issue #903. One replay is therefore granted to a prompt conflict whatever the clock says; see
     * {@link #replayable(int, long, Throwable, String)}. The window is checked between attempts, so an attempt
     * already running is never interrupted: a conflicted operation holds its caller for the window plus one
     * attempt, and a prompt conflict for two attempts when that is longer.
     * <p>
     * Only the operation itself is replayed: a failure of {@link #getConnection()} or of the implicit
     * {@link Connection#close()} - which returns the connection to the pool after a rollback - leaves the loop, so
@@ -877,7 +867,7 @@
     */
    @Override
    public void write(WriteOperation writeOperation) throws Exception {
        final long startedAt=System.nanoTime();
        final long startedAt=nanoTime();
        for (int attempt=1;;attempt++) {
            Exception failure=null;
            String driver=null;
@@ -907,14 +897,24 @@
                    throw e;
                }
            }
            //System.nanoTime()-startedAt is the overflow safe form of the elapsed time
            if (!replayable(attempt, System.nanoTime()-startedAt, failure, driver)) {
            //nanoTime()-startedAt is the overflow safe form of the elapsed time
            final long elapsedNanos=nanoTime()-startedAt;
            if (!replayable(attempt, elapsedNanos, failure, driver)) {
                throw failure;
            }
            //logged rather than silently absorbed, so that a deployment retrying most of its writes stays observable;
            //one line per replay, since an add can emit nine of them and a stack trace each time reads as a failure
            logger.warn(LocalizableMessage.raw("jdbc: replaying the transaction after a conflict, attempt %d of %d: %s",
                    attempt, MAX_RETRIES, conflictSummary(failure)));
            //one line per replay, since an add can emit nine of them and a stack trace each time reads as a failure.
            //Both bounds are named, and the attempt count is the one that rarely fires: a replay usually stops
            //because the window ran out, and a log naming only MAX_RETRIES leaves an operation that gave up at
            //attempt 2 of a promised 10 with nothing saying why. Milliseconds rather than seconds, since the
            //engines report a deadlock in a few of them and whole seconds would read "0" for most of a burst; and
            //the one line that replays past its own window says so, rather than reading as a bound not honoured
            logger.warn(LocalizableMessage.raw(
                    "jdbc: replaying the transaction after a %s conflict, attempt %d of %d, %d ms elapsed of the %d ms window%s: %s",
                    conflictOf(failure, driver), attempt, MAX_RETRIES, TimeUnit.NANOSECONDS.toMillis(elapsedNanos),
                    TimeUnit.NANOSECONDS.toMillis(RETRY_WINDOW_NANOS),
                    elapsedNanos>=RETRY_WINDOW_NANOS ? " (the first replay, granted past it)" : "",
                    conflictSummary(failure)));
            if (logger.isTraceEnabled()) {
                logger.trace("jdbc: the conflict being replayed was %s", stackTraceToSingleLineString(failure));
            }
@@ -931,6 +931,15 @@
        }
    }

    /**
     * The clock {@link #write} measures its retry window with, read once before the first attempt and once after
     * each. Overridable so that a test can script it: what the window bounds is the whole run of attempts, not
     * each attempt on its own, and the difference between the two is a single {@code startedAt} outside the loop.
     */
    long nanoTime() {
        return System.nanoTime();
    }

    /** Returns the randomized delay before the given attempt is replayed, doubling with each attempt up to a cap. */
    static long retryDelayMillis(int attempt) {
        final double bound=Math.min(MAX_SLEEP_ON_RETRY_MS, BASE_SLEEP_ON_RETRY_MS * (1 << Math.min(attempt-1, 5)));
@@ -938,32 +947,9 @@
    }

    /**
     * Returns whether the given failure carries a transaction conflict that replaying the operation can resolve.
     * <p>
     * The conflict is looked up along the whole cause chain because it reaches this class wrapped: a deadlock in
     * {@code put} arrives as {@code StorageRuntimeException(SQLException)}, and a caller such as
     * {@code EntryContainer.addEntry} may wrap it once more.
     * <p>
     * The standard class 40 states carry the conflict of most engines - 40P01 for PostgreSQL, 40001 for SQL Server
     * and for MySQL, whose driver replaces the server side HY000 of a deadlock and of a lock wait timeout with
     * 40001 - but not of all of them, so the vendor error numbers are consulted as well, keyed by the driver in the
     * same way {@code getTableDialect} keys the column types. They cannot be matched driver-independently: Oracle
     * reports a deadlock as ORA-00060 with SQLState 61000, and gives 1205 to a fatal "not a data file" error that
     * no replay can resolve, while 1205 is exactly the deadlock victim of SQL Server. The SQL Server number is
     * matched beyond its class 40 state because a deployment may add {@code xopenStates=true} to its connection
     * URL, which reports the same deadlock as 42000. MySQL needs no number of its own, since its driver has already
     * mapped both conditions into class 40 - its number is read by {@link #conflictOf} alone, and only to tell the
     * two apart; see {@link #NON_REPLAYABLE_ROLLBACK_STATES} for the two class 40 states that are excluded from
     * that match.
     */
    static boolean isRetryableConflict(Throwable t, String driver) {
        return conflictOf(t, driver)!=Conflict.NONE;
    }

    /**
     * The class of a failure. Whether it is a conflict at all is what decides that the operation is replayed;
     * which of the two remaining classes it is decides only how long the replays may go on for, since the wait an
     * engine spends before reporting a conflict is charged to the attempt that hit it.
     * which of the two remaining classes it is decides only whether the first replay is granted unconditionally,
     * since the wait an engine spends before reporting a conflict is charged to the attempt that hit it.
     */
    enum Conflict {
        /** Not a conflict: no replay resolves it. */
@@ -975,19 +961,40 @@
    }

    /**
     * Returns the class of the first conflict of the given cause chain, walked as
     * {@link #isRetryableConflict(Throwable, String)} describes, or {@link Conflict#NONE} if it carries none.
     * Returns the class of the conflict the given failure carries, or {@link Conflict#NONE} if it carries none,
     * which is what decides whether replaying the operation can resolve it.
     * <p>
     * The conflict is looked up along the whole cause chain because it reaches this class wrapped: a deadlock in
     * {@code put} arrives as {@code StorageRuntimeException(SQLException)}, and a caller such as
     * {@code EntryContainer.addEntry} may wrap it once more. The chain is walked to its end rather than stopped at
     * the first conflict found, so that the most specific class in it wins: a wrapper that carries a class 40 state
     * of its own but no vendor number would otherwise downgrade the {@link Conflict#AFTER_LOCK_WAIT} of the
     * {@link SQLException} it wraps, and hand a wait the engine already bounded a replay it does not need.
     * <p>
     * The standard class 40 states carry the conflict of most engines - 40P01 for PostgreSQL, 40001 for SQL Server
     * and for MySQL, whose driver replaces the server side HY000 of a deadlock and of a lock wait timeout with
     * 40001 - but not of all of them, so the vendor error numbers are consulted as well, keyed by the driver in the
     * same way {@code getTableDialect} keys the column types. They cannot be matched driver-independently: Oracle
     * reports a deadlock as ORA-00060 with SQLState 61000, and gives 1205 to a fatal "not a data file" error that
     * no replay can resolve, while 1205 is exactly the deadlock victim of SQL Server. The SQL Server number is
     * matched beyond its class 40 state because a deployment may add {@code xopenStates=true} to its connection
     * URL, which reports the same deadlock as 42000. MySQL needs no number of its own for the match, since its
     * driver has already mapped both conditions into class 40 - its number is read by {@link #classOf} alone, and
     * only to tell the two apart; see {@link #NON_REPLAYABLE_ROLLBACK_STATES} for the two class 40 states that are
     * excluded from that match.
     */
    static Conflict conflictOf(Throwable t, String driver) {
        Conflict found=Conflict.NONE;
        for (int hop=0; t!=null && hop<MAX_CAUSE_HOPS; t=t.getCause(), hop++) {
            if (t instanceof SQLException) {
                final Conflict conflict=classOf((SQLException) t, driver);
                if (conflict!=Conflict.NONE) {
                if (conflict==Conflict.AFTER_LOCK_WAIT) { // the most specific there is: no later hop refines it
                    return conflict;
                }
                found=conflict!=Conflict.NONE ? conflict : found;
            }
        }
        return Conflict.NONE;
        return found;
    }

    /**
@@ -1005,28 +1012,28 @@

    /**
     * Returns whether the failure of the given attempt is replayed: the decision {@link #write} takes after every
     * attempt, made here apart from the clock so that it can be tested without a database. The first replay of a
     * conflict is never denied, because the wait an engine spends before reporting one is charged to the attempt
     * that hit it and is unbounded on three of the four engines here, so there is no window that some wait does not
     * outlast; bounding that wait itself would take a session lock timeout on the transaction connection. The
     * replays after it are bounded by the window of the class of the conflict, against the time elapsed since the
     * first attempt began.
     * attempt, made here apart from the clock so that it can be tested without a database. Replays are bounded by
     * {@link #MAX_RETRIES} and by {@link #RETRY_WINDOW_NANOS} against the time elapsed since the first attempt
     * began, with one grant on top of those two bounds: the first replay of a {@link Conflict#PROMPT} conflict is
     * never denied by the clock. The wait an engine spends before reporting one of those is charged to the attempt
     * that hit it and is unbounded on three of the four engines here - SQL Server took some 12 s to pick a victim
     * in CI - so there is no window that some wait does not outlast, and measuring one against it only leaves the
     * operation with no replay at all. The grant does not extend to {@link Conflict#AFTER_LOCK_WAIT}, whose wait
     * the engine has already bounded for us: replaying that costs the same bounded wait again, which is exactly
     * what the window is here to refuse. Bounding the prompt wait too, with a session lock timeout on the
     * transaction connection, is what would let the window govern both classes and retire this grant.
     */
    static boolean replayable(int attempt, long elapsedNanos, Throwable failure, String driver) {
        final Conflict conflict=conflictOf(failure, driver);
        if (conflict==Conflict.NONE || attempt>=MAX_RETRIES) {
            return false;
        }
        //the engine asked for the transaction to be rerun: no clock denies that first rerun
        if (attempt==1) {
        //the engine asked for the transaction to be rerun after a wait nothing here bounds: no clock denies that
        //first rerun, since the window it would be measured against was spent by the wait rather than by a replay
        if (attempt==1 && conflict==Conflict.PROMPT) {
            return true;
        }
        return elapsedNanos<windowOf(conflict);
    }

    /** Returns the window the replays of the given conflict are bounded by; {@link Conflict#NONE} never gets here. */
    private static long windowOf(Conflict conflict) {
        return conflict==Conflict.AFTER_LOCK_WAIT ? LOCK_WAIT_RETRY_WINDOW_NANOS : PROMPT_CONFLICT_RETRY_WINDOW_NANOS;
        return elapsedNanos<RETRY_WINDOW_NANOS;
    }

    private static boolean isConflict(SQLException e, String driver) {

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

@@ -15,27 +15,36 @@
 */
package org.opends.server.backends.jdbc;

import org.forgerock.opendj.server.config.server.JDBCBackendCfg;
import org.opends.server.DirectoryServerTestCase;
import org.opends.server.backends.jdbc.JDBCStorage.Conflict;
import org.opends.server.backends.pluggable.spi.AccessMode;
import org.opends.server.backends.pluggable.spi.StorageRuntimeException;
import org.opends.server.backends.pluggable.spi.WriteOperation;
import org.opends.server.backends.pluggable.spi.WriteableTransaction;
import org.opends.server.types.DirectoryException;
import org.testng.annotations.DataProvider;
import org.testng.annotations.Test;

import java.sql.Connection;
import java.sql.SQLException;
import java.util.concurrent.TimeUnit;
import java.util.concurrent.atomic.AtomicInteger;

import static org.forgerock.i18n.LocalizableMessage.raw;
import static org.forgerock.opendj.ldap.ResultCode.OTHER;
import static org.mockito.Mockito.mock;
import static org.opends.server.backends.jdbc.JDBCStorage.Conflict.AFTER_LOCK_WAIT;
import static org.opends.server.backends.jdbc.JDBCStorage.Conflict.NONE;
import static org.opends.server.backends.jdbc.JDBCStorage.Conflict.PROMPT;
import static org.testng.Assert.assertEquals;
import static org.testng.Assert.assertSame;
import static org.testng.Assert.assertTrue;

/**
 * Tests how a failure is classified as a transaction conflict, which is what decides whether
 * {@link JDBCStorage#write} replays the operation, how long the replays may go on for, and how long it waits
 * before each of them.
 * {@link JDBCStorage#write} replays the operation and whether its first replay is granted regardless of the
 * clock, how long the replays may go on for, and how long it waits before each of them.
 * <p>
 * Runs without a database: the failures the drivers report are reproduced as synthetic
 * {@link SQLException}s carrying the same vendor error number and SQLState.
@@ -124,17 +133,20 @@
      // number read to date that conflict refines a match its state has already made, and never makes one of its own
      { "mysql lock wait timeout, server state", sql(1205, "HY000"), MYSQL, NONE },
      { "cyclic cause chain", new SelfCausedException(), MSSQL, NONE },

      // the chain is walked to its end, not stopped at its first conflict: a hop carrying a bare class 40 state
      // is a conflict by itself, and returning it would hand the lock wait timeout it wraps - a wait MySQL has
      // already bounded - the replay that only the conflicts nothing bounds are granted
      { "lock wait timeout under a bare class 40 wrapper", sql(0, "40001", sql(1205, "40001")), MYSQL,
        AFTER_LOCK_WAIT },
      { "bare class 40 wrapper over a deadlock", sql(0, "40001", sql(1213, "40001")), MYSQL, PROMPT },
    };
  }

  /** Whether a failure is replayed at all is what the classification decides first; the class does not change it. */
  @Test(dataProvider = "failures")
  public void testIsRetryableConflict(String name, Throwable failure, String driver, Conflict expected)
  {
    assertEquals(JDBCStorage.isRetryableConflict(failure, driver), expected != NONE, name);
  }

  /** Which class it lands in decides only how long its replays may go on for. */
  /**
   * Whether a failure is a conflict at all decides that it is replayed; which class of conflict it is decides
   * only whether its first replay is granted regardless of the clock.
   */
  @Test(dataProvider = "failures")
  public void testConflictClass(String name, Throwable failure, String driver, Conflict expected)
  {
@@ -142,34 +154,41 @@
  }

  /**
   * Which replays happen. The first one is never denied, since the wait an engine spends before reporting a
   * conflict is charged to the attempt that hit it and no window can be chosen that some wait does not outlast;
   * the replays after it are bounded by the window of the class of the conflict.
   * Which replays happen. The window bounds them from the first attempt, with one grant: a conflict its engine
   * reports promptly is given its first replay whatever the clock says, since the wait charged to the attempt
   * that hit it is unbounded and no window survives it. A conflict the engine reported only after a lock wait
   * timeout of its own gets no such grant - that wait is bounded already, and repeating it is what the window
   * refuses.
   */
  @DataProvider
  public Object[][] replays()
  {
    return new Object[][] {
      // the engine asked for the transaction to be rerun, and no clock denies that first rerun. The failure of run
      // 33010633197 is the case: SQL Server leaves the lock wait unbounded, so its deadlock monitor picked a victim
      // ~12 s into the first attempt, and a window of any size is outlasted by some wait
      // the engine asked for the transaction to be rerun after a wait nothing here bounds, and no clock denies
      // that first rerun. The failure of run 33010633197 is the case: SQL Server leaves the lock wait unbounded,
      // so its deadlock monitor picked a victim ~12 s into the first attempt, and master replayed it zero times
      { "deadlock reported after a long lock wait", 1, seconds(12), sql(1205, "40001"), MSSQL, true },
      { "deadlock reported later than any window", 1, seconds(600), sql(1205, "40001"), MSSQL, true },
      // what granting it costs is one more wait of the engine that waits longest, and only once
      { "mysql lock wait timeout, first attempt", 1, seconds(50), sql(1205, "40001"), MYSQL, true },

      // the replays after the first are what the window bounds, so that a conflict which never clears is failed
      // rather than never returned
      { "deadlock within the window", 2, seconds(59), sql(1205, "40001"), MSSQL, true },
      { "deadlock at the window", 2, seconds(60), sql(1205, "40001"), MSSQL, false },
      { "deadlock past the window", 2, seconds(61), sql(1205, "40001"), MSSQL, false },
      // MySQL reports a lock wait timeout only after innodb_lock_wait_timeout, 50 s by default: ten attempts of
      // those park a worker thread for eight minutes, which is the wait the narrower window exists to bound
      { "mysql lock wait timeout within its window", 2, seconds(9), sql(1205, "40001"), MYSQL, true },
      { "mysql lock wait timeout at its window", 2, seconds(10), sql(1205, "40001"), MYSQL, false },
      { "mysql lock wait timeout past its window", 2, seconds(12), sql(1205, "40001"), MYSQL, false },
      // the two MySQL numbers part ways here: a deadlock is reported as promptly as any other engine reports one
      { "mysql deadlock", 2, seconds(12), sql(1213, "40001"), MYSQL, true },
      // the grant is one replay, not an exemption: from the second attempt on the window governs, so that a
      // conflict which never clears is failed rather than never returned
      { "deadlock within the window", 2, seconds(9), sql(1205, "40001"), MSSQL, true },
      { "deadlock at the window", 2, seconds(10), sql(1205, "40001"), MSSQL, false },
      // the same elapsed time that was granted on attempt 1 is refused on attempt 2: one grant, and only one
      { "deadlock past the window", 2, seconds(12), sql(1205, "40001"), MSSQL, false },
      // a MySQL deadlock is reported as promptly as any other engine reports one, so it is granted the same
      { "mysql deadlock, first attempt", 1, seconds(12), sql(1213, "40001"), MYSQL, true },
      { "mysql deadlock, past the window", 2, seconds(12), sql(1213, "40001"), MYSQL, false },

      // MySQL reports a lock wait timeout only after innodb_lock_wait_timeout, 50 s by default: that wait is
      // bounded by the engine, so the window is measured against it from the first attempt and a second 50 s wait
      // is refused - which is the whole reason the window was introduced
      { "mysql lock wait timeout at the default 50 s", 1, seconds(50), sql(1205, "40001"), MYSQL, false },
      { "mysql lock wait timeout past the window", 1, seconds(12), sql(1205, "40001"), MYSQL, false },
      // ... and a deployment that tuned innodb_lock_wait_timeout below the window still gets its replays
      { "mysql lock wait timeout tuned under the window", 1, seconds(3), sql(1205, "40001"), MYSQL, true },
      { "mysql lock wait timeout, second attempt within", 2, seconds(6), sql(1205, "40001"), MYSQL, true },
      { "mysql lock wait timeout, second attempt at the window", 2, seconds(10), sql(1205, "40001"), MYSQL, false },

      // the attempt count bounds every class, whatever the window has left
      { "last attempt left", 9, 0L, sql(1205, "40001"), MSSQL, true },
@@ -234,8 +253,90 @@
    return new SQLException("synthetic failure", sqlState, errorCode);
  }

  private static SQLException sql(int errorCode, String sqlState, Throwable cause)
  {
    return new SQLException("synthetic failure", sqlState, errorCode, cause);
  }

  private static long seconds(long seconds)
  {
    return seconds * 1000L * 1000L * 1000L;
    return TimeUnit.SECONDS.toNanos(seconds);
  }

  /**
   * How {@link JDBCStorage#write} drives the two decisions above, which the cases before this one cannot see:
   * they are handed an elapsed time and an attempt number rather than producing them. The clock is scripted and
   * advances a fixed step per read, so the attempts made and the reads taken are both exact.
   * <p>
   * Between them the rows pin the two lines the rest of the file would let a refactor take away. A single
   * {@code startedAt} outside the retry loop is what makes the window bound the whole run rather than each
   * attempt: moved inside, every attempt is measured against its own start, sees the step and nothing more, and
   * replays to MAX_RETRIES. And the grant of the first replay is what issue #903 is about: without it an attempt
   * that alone outlasts the window leaves the loop with no replay at all.
   */
  @DataProvider
  public Object[][] writeRuns()
  {
    return new Object[][] {
      // a step under the window, so the window is what ends the run: attempt 1 is granted its replay at 4 s,
      // attempt 2 is inside the window at 8 s, attempt 3 is past it at 12 s. With startedAt inside the loop every
      // attempt measures 4 s, never reaches the window, and the run goes to MAX_RETRIES instead
      { "the window bounds the run, not the attempt", 4L, 3, 4 },
      // a step past the window, so only the grant can produce a second attempt: remove it and the run ends on the
      // first. With startedAt inside the loop the attempts still come to two, but each takes a read of its own
      { "the first replay is granted past the window", 12L, 2, 3 },
    };
  }

  @Test(dataProvider = "writeRuns")
  public void testWriteDrivesTheRetryLoop(String name, final long stepSeconds, int expectedAttempts,
      int expectedClockReads) throws Exception
  {
    final AtomicInteger clockReads = new AtomicInteger();
    final AtomicInteger attempts = new AtomicInteger();
    final Connection connection = mock(Connection.class);
    // no driver name matches a mock, so this is classified by its class 40 state alone: a prompt conflict
    final SQLException conflict = sql(0, "40001");

    final JDBCStorage storage = new JDBCStorage(mock(JDBCBackendCfg.class), null)
    {
      @Override
      Connection getConnection()
      {
        return connection;
      }

      @Override
      long nanoTime()
      {
        return seconds(stepSeconds * clockReads.getAndIncrement());
      }
    };
    storage.accessMode = AccessMode.READ_WRITE;

    StorageRuntimeException thrown = null;
    try
    {
      storage.write(new WriteOperation()
      {
        @Override
        public void run(WriteableTransaction txn)
        {
          attempts.incrementAndGet();
          throw new StorageRuntimeException(conflict);
        }
      });
    }
    catch (StorageRuntimeException e)
    {
      thrown = e;
    }

    assertSame(thrown != null ? thrown.getCause() : null, conflict, name + ": the conflict reaches the caller");
    assertEquals(attempts.get(), expectedAttempts, name + ": attempts made");
    // read once before the loop and once after each attempt. The count is asserted, not just the placement,
    // because the clock advances per read rather than per attempt: a second read added inside an attempt would
    // halve the effective step and change the run without either row saying so
    assertEquals(clockReads.get(), expectedClockReads, name + ": clock reads");
  }
}