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

maximthomas
yesterday 2a9c912bfe7f81488affaf7c83711c6de189aa40
[#903] Report the grant instead of inferring it, and read the conflict class once

Round 3 of review on #904.

Report rather than infer. The line that says "the first replay, granted past it" was derived from
elapsed >= window, which coincides with the grant only while that grant is the sole way past the
window; grantedPastTheWindow() is now a question of its own, and both the loop and the log ask it.

Read the class once. write() calls conflictOf() and hands the result to replayReason() and to the
bounds, which no longer take a driver name at all: three walks of the chains per failed attempt
become one, two callers can no longer drift into disagreeing about the same failure, and the warn
is guarded by isWarnEnabled() so a server with no error-log publisher builds none of it.

Name the link the class was decided on. conflictOf() keeps the most specific class in the chains
while conflictSummary() named the first conflict it met, so a lock wait timeout under a bare class
40 wrapper logged "error 0" - the 1205 that chose the bound never appeared.

Delete replayable() and isRetryableConflict(). Both had become wrappers no src/main caller reaches
after the split; their content is one comparison at each site.

State the MySQL trade in the javadoc of the window rather than in a test row: at the stock
innodb_lock_wait_timeout a lock wait timeout is reported past the window on the first check and
gets no grant, so it is never replayed. Master behaved the same way and said nothing.

Advance the scripted clock of testWriteDrivesTheRetryLoop per attempt instead of per read, which
retires the assertion on the number of reads and with it the coupling to the fixture. Both mutants
still die: deleting the grant gives "attempts made expected [2] but found [1]", and a startedAt
moved inside the loop gives "expected [3] but found [10]".

Filed #915 for bounding the attempt itself - the change that retires the grant, the Conflict enum
and the driver-keyed vendor number together - with the 1222/55P03 classification it has to carry.
2 files modified
301 ■■■■■ changed files
opendj-server-legacy/src/main/java/org/opends/server/backends/jdbc/JDBCStorage.java 164 ●●●●● patch | view | raw | blame | history
opendj-server-legacy/src/test/java/org/opends/server/backends/jdbc/JDBCStorageRetryTest.java 137 ●●●● patch | view | raw | blame | history
opendj-server-legacy/src/main/java/org/opends/server/backends/jdbc/JDBCStorage.java
@@ -57,14 +57,21 @@
    /**
     * 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.
     * applies from the first check, with the single exception {@link #grantedPastTheWindow} 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.
     * <p>
     * What that costs, stated rather than left to be read off a test row: at the stock innodb_lock_wait_timeout a
     * MySQL lock wait timeout is reported at ~50 s, which is past this window on the first check, so such a write
     * is never replayed at all - the one conflict class of the set that a MySQL deployment sees most, and the one
     * whose replay would most reliably succeed. It is the deliberate half of the trade the other half of which is
     * #903: one bounded wait beats two, and a deployment that tunes innodb_lock_wait_timeout below this window
     * gets its replays back. The trade only exists because nothing here bounds the attempt: with a session lock
     * timeout on the transaction connection (#915) every wait would be shorter than this window, the tuned-down
     * case would become the normal one, and this window would govern both classes with no grant needed at all.
     */
    private static final long RETRY_WINDOW_NANOS = TimeUnit.SECONDS.toNanos(10);
@@ -93,11 +100,11 @@
    private static final int ORACLE_DEADLOCK_DETECTED = 60;
    /**
     * MySQL error number of a lock wait timeout, ER_LOCK_WAIT_TIMEOUT. Connector/J maps it to the same class 40
     * state as a deadlock, so it is a conflict like any other and this number is only what tells the two apart:
     * of every conflict handled here it is the one an engine reports late rather than promptly. It is keyed by the
     * driver like the numbers above, since the engines collide on it - the same 1205 is the deadlock victim of
     * SQL Server and a fatal "not a data file" on Oracle.
     * MySQL error number of a lock wait timeout, ER_LOCK_WAIT_TIMEOUT: the one conflict of the set an engine
     * reports late rather than promptly. Connector/J maps it to the same class 40 state as a deadlock, so this
     * number is not what matches it - it only tells the two apart, and only under a MySQL driver. That it repeats
     * the literal of {@link #MSSQL_DEADLOCK_VICTIM} is the collision {@link #conflictOf} keys every vendor number
     * by the driver for, and is stated there rather than again here.
     */
    private static final int MYSQL_LOCK_WAIT_TIMEOUT = 1205;
@@ -909,9 +916,9 @@
     * 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.
     * {@link #grantedPastTheWindow}. 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
@@ -922,7 +929,7 @@
     * connection handed out unvalidated and found dead costs an attempt rather than the operation, and a write of
     * the replication replay - which records a failed operation as applied and advances the server state past it,
     * see #889 - never sees it. Only while nothing of the attempt may have been committed yet, though: see
     * {@link #replayReason(Throwable, String, boolean, boolean, boolean)}.
     * {@link #replayReason(Conflict, Throwable, boolean, boolean, boolean)}.
     */
    @Override
    public void write(WriteOperation writeOperation) throws Exception {
@@ -1013,10 +1020,13 @@
            //still allowed, which is the attempt count and the window of #903. Neither subsumes the other: a
            //dropped connection is worth replaying and carries no conflict class, while a conflict past both
            //bounds is not replayed however plainly it is one
            final String reason=replayReason(failure,driver,committing,partlyCommitted,dropped);
            //classified once and handed to both questions: the walk of the chains is bounded but not free, and
            //two callers asking it apart could drift into disagreeing about the same failure
            final Conflict conflict=conflictOf(failure,driver);
            final String reason=replayReason(conflict,failure,committing,partlyCommitted,dropped);
            //nanoTime()-startedAt is the overflow safe form of the elapsed time
            final long elapsedNanos=nanoTime()-startedAt;
            if (reason==null || !replayableWithin(attempt, elapsedNanos, failure, driver)) {
            if (reason==null || !replayableWithin(attempt, elapsedNanos, conflict)) {
                throw failure;
            }
            //logged rather than silently absorbed, so that a deployment retrying most of its writes stays observable;
@@ -1025,13 +1035,18 @@
            //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 %s, attempt %d of %d, %d ms elapsed of the %d ms window%s: %s",
                    reason, 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, driver)));
            //the one line that replays past its own window says so, rather than reading as a bound not honoured -
            //asked of the predicate the loop just acted on rather than re-derived from the clock, so that the
            //claim cannot outlive the grant that justifies it
            if (logger.isWarnEnabled()) {
                logger.warn(LocalizableMessage.raw(
                        "jdbc: replaying the transaction after %s, attempt %d of %d, %d ms elapsed of the %d ms window%s: %s",
                        reason, attempt, MAX_RETRIES, TimeUnit.NANOSECONDS.toMillis(elapsedNanos),
                        TimeUnit.NANOSECONDS.toMillis(RETRY_WINDOW_NANOS),
                        grantedPastTheWindow(attempt, elapsedNanos, conflict)
                                ? " (the first replay, granted past it)" : "",
                        conflictSummary(failure, driver)));
            }
            if (logger.isTraceEnabled()) {
                logger.trace("jdbc: the failure being replayed was %s", stackTraceToSingleLineString(failure));
            }
@@ -1063,9 +1078,9 @@
     * <p>
     * A transaction conflict is replayable whichever phase reported it: the engine rolled the transaction back
     * before it answered. It is read from the failure of the operation only, never from the release of the
     * connection - see {@link #isRetryableConflict} - since the release runs after the outcome was decided and
     * cannot make that claim for it. A connection the database dropped is replayable only while the transaction
     * had not been committed yet. A drop reported by {@code commit()} leaves the outcome unknown - the server may
     * connection - see {@link #conflictOf} - since the release runs after the outcome was decided and cannot make
     * that claim for it. A connection the database dropped is replayable only while the transaction had not been
     * committed yet. A drop reported by {@code commit()} leaves the outcome unknown - the server may
     * have committed and died before the answer reached us - and replaying a write that in fact committed applies
     * it twice, which is the very reason 40003 is one of {@link #NON_REPLAYABLE_ROLLBACK_STATES}.
     * <p>
@@ -1078,17 +1093,18 @@
     * second time and fails with ERR_ENTRY_CONTAINER_ALREADY_REGISTERED, which masks the failure that caused the
     * replay and leaves the indexes of the previous attempt behind with their configuration listeners.
     *
     * @param conflict the class {@link #conflictOf} read from the failure, asked of it once by the caller
     * @param committing whether the failure was reported by {@code commit()}, which leaves the outcome unknown
     * @param partlyCommitted whether the attempt committed part of its work before it failed
     * @param connectionClosed whether the driver closed the connection under the failure - evidence no SQLState
     * carries on mssql-jdbc, which reports a killed session as S0001 and closes the connection behind it
     */
    static String replayReason(Throwable failure, String driver, boolean committing, boolean partlyCommitted,
    static String replayReason(Conflict conflict, Throwable failure, boolean committing, boolean partlyCommitted,
            boolean connectionClosed) {
        if (partlyCommitted) {
            return null;
        }
        if (isRetryableConflict(failure, driver)) {
        if (conflict!=Conflict.NONE) {
            return "a conflict";
        }
        if (!committing && (connectionClosed || isConnectionFailure(failure))) {
@@ -1280,6 +1296,15 @@
     * Returns the class of a single failure. The vendor number only refines a failure {@link #isConflict} has
     * already matched and never widens that match, which the engines colliding on 1205 do not allow: the number is
     * read here to tell the late conflict of MySQL from the deadlock its driver reports under the same state.
     * <p>
     * A conflict raised under a driver none of the four engines is recognised in is {@link Conflict#PROMPT}, the
     * same answer the rest of this class gives an unrecognised driver: {@code getTableDialect} hands it the
     * PostgreSQL column types, {@code upsert} the ANSI statement, and PostgreSQL has no late conflict to tell
     * apart - its lock_timeout is unlimited by default, so 40001 and 40P01 are both reported as soon as they are
     * detected. A MySQL-wire-compatible driver would be classified that way too, and would take the grant that a
     * lock wait timeout must not have; it cannot reach this code, because such a deployment fails long before a
     * transaction of it can conflict - {@code openTree(createOnDemand)} issues {@code create table ... k bytea},
     * a type no MySQL-wire engine has.
     */
    private static Conflict classOf(SQLException e, String driver) {
        if (!isConflict(e, driver)) {
@@ -1290,51 +1315,48 @@
    }
    /**
     * 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. 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.
     * Whether another attempt is still allowed: the bounds half of the decision {@link #write} takes after every
     * attempt, asked of a failure {@link #replayReason} has already found worth replaying and made here apart
     * from the clock so that it can be tested without a database. It is asked of the conflict class rather than
     * of the failure because not every replayable failure carries one - a connection the database dropped is
     * replayed on the evidence of the drop, and would be refused by a bound that first insisted on a class 40
     * state - and because {@code write()} has already read that class off the failure once.
     * <p>
     * Replays are bounded by {@link #MAX_RETRIES} and by {@link #RETRY_WINDOW_NANOS} against the time elapsed
     * since the first attempt began, with the one grant {@link #grantedPastTheWindow} states on top of them.
     */
    static boolean replayable(int attempt, long elapsedNanos, Throwable failure, String driver) {
        return conflictOf(failure, driver)!=Conflict.NONE
                && replayableWithin(attempt, elapsedNanos, failure, driver);
    }
    /**
     * The bounds half of {@link #replayable}, asked of a failure {@link #replayReason} has already found worth
     * replaying. Split from the class half because the two answer different questions and not every replayable
     * failure carries a conflict class: a connection the database dropped is replayed on the evidence of the drop,
     * and would be refused by a bound that first insisted on a class 40 state.
     */
    static boolean replayableWithin(int attempt, long elapsedNanos, Throwable failure, String driver) {
    static boolean replayableWithin(int attempt, long elapsedNanos, Conflict conflict) {
        if (attempt>=MAX_RETRIES) {
            return false;
        }
        //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 && conflictOf(failure, driver)==Conflict.PROMPT) {
        if (grantedPastTheWindow(attempt, elapsedNanos, conflict)) {
            return true;
        }
        return elapsedNanos<RETRY_WINDOW_NANOS;
    }
    /**
     * Whether the failure carries a transaction conflict, which is {@link #conflictOf} asked as a yes or no. Read
     * without the suppressed exceptions, unlike {@link #isConnectionFailure}: a conflict is replayed whichever
     * phase reported it, on the strength of the engine having rolled the transaction back before it answered - and
     * the release of the connection runs after the outcome was decided and cannot make that claim. A class 40
     * raised there would otherwise replay a transaction commit() left in doubt, which is what the committing
     * guard of replayReason() exists to prevent.
     * Whether this replay is the one {@link #RETRY_WINDOW_NANOS} does not get to deny: the first replay of a
     * conflict its engine reports promptly, taken although the window is already spent. The wait an engine spends
     * before reporting such a conflict 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, which is issue
     * #903. 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.
     * <p>
     * Asked as a question of its own so that the line reporting the replay can name the bound that was actually
     * applied instead of inferring it from the clock: {@code elapsed >= window} coincides with this grant only
     * for as long as this stays the sole way past the window, and a line that keeps claiming "the first replay"
     * after that would be describing a decision nobody took.
     * <p>
     * {@code attempt==1} is a proxy and not the invariant: the invariant is that no clock can bound a wait
     * nothing else bounds, and that holds on every attempt, not only the first. Widening the grant to all of them
     * would leave {@link #MAX_RETRIES} as the only real cap, so it is held to one replay until the attempt itself
     * carries a lock bound - see #915, which retires this method rather than widening it.
     */
    static boolean isRetryableConflict(Throwable t, String driver) {
        return conflictOf(t, driver)!=Conflict.NONE;
    static boolean grantedPastTheWindow(int attempt, long elapsedNanos, Conflict conflict) {
        return attempt==1 && conflict==Conflict.PROMPT && elapsedNanos>=RETRY_WINDOW_NANOS;
    }
    private static boolean isConflict(SQLException e, String driver) {
@@ -1361,9 +1383,15 @@
     * none.
     */
    static String conflictSummary(Throwable failure, String driver) {
        // asked in the order replayReason() asks it, and of the same chains, so that the line names the link the
        // decision was taken on rather than one that merely resembles it
        SQLException named=firstLinkMatching(failure, WITHOUT_THE_RELEASE, e -> isConflict(e, driver));
        // asked in the order conflictOf() asks it, and of the same chains, so that the line names the link the
        // decision was taken on rather than one that merely resembles it: the most specific class first, since a
        // wrapper carrying a bare class 40 state is a conflict of its own and naming it would leave the vendor
        // number that decided the class out of the only record the replay leaves
        SQLException named=firstLinkMatching(failure, WITHOUT_THE_RELEASE,
                e -> classOf(e, driver)==Conflict.AFTER_LOCK_WAIT);
        if (named==null) {
            named=firstLinkMatching(failure, WITHOUT_THE_RELEASE, e -> isConflict(e, driver));
        }
        if (named==null) {
            named=firstLinkMatching(failure, WITH_THE_RELEASE, JDBCStorage::saysTheConnectionIsGone);
        }
opendj-server-legacy/src/test/java/org/opends/server/backends/jdbc/JDBCStorageRetryTest.java
@@ -249,19 +249,58 @@
      { "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
      // the attempt count bounds every class, whatever the window has left. It is the bound that rarely fires:
      // reaching it takes ten attempts inside a 10 s window, which only a conflict reported in milliseconds
      // leaves room for - a conflict preceded by a wait longer than the window stops at two attempts, the
      // granted one included, and the line reporting the replay names the window for that reason
      { "last attempt left", 9, 0L, sql(1205, "40001"), MSSQL, true },
      { "attempts exhausted", 10, 0L, sql(1205, "40001"), MSSQL, false },
      // and nothing a replay resolves is replayed, the first attempt included
      { "not a conflict", 1, 0L, sql(2627, "23000"), MSSQL, false },
      // a failure carrying no conflict class at all still passes these bounds: what makes it replayable is
      // replayReason(), which write() asks first, and a dropped connection carries no class 40 state
      { "a drop, which no class describes", 1, 0L, sql(2627, "23000"), MSSQL, true },
    };
  }
  /**
   * Composed the way {@code write()} composes it: the class is read off the failure once, and the bounds are
   * asked of the class. Whether the failure is worth replaying at all is {@code replayReason()}, tested apart.
   */
  @Test(dataProvider = "replays")
  public void testReplayable(String name, int attempt, long elapsedNanos, Throwable failure, String driver,
      boolean expected)
  {
    assertEquals(JDBCStorage.replayable(attempt, elapsedNanos, failure, driver), expected, name);
    assertEquals(JDBCStorage.replayableWithin(attempt, elapsedNanos, JDBCStorage.conflictOf(failure, driver)),
        expected, name);
  }
  /**
   * The grant is reported rather than inferred: the line reporting a replay says "granted past it" only where
   * the loop really took that branch. Pinned apart from {@link #testReplayable} because the two agree today by
   * construction - a replay past the window can only be the grant - and it is that coincidence, not the claim,
   * that a later change to the bounds would take away.
   */
  @Test
  public void testTheGrantIsTheOnlyReplayPastTheWindow()
  {
    // the grant, and the only shape of it: the first replay of a conflict reported past the window
    assertTrue(JDBCStorage.grantedPastTheWindow(1, seconds(12), PROMPT), "the conflict of #903 was not granted");
    // inside the window nothing is granted - the window itself allows the replay, and the line says nothing
    assertFalse(JDBCStorage.grantedPastTheWindow(1, seconds(9), PROMPT), "a replay inside the window was granted");
    // and past the first attempt, or for a wait the engine already bounded, there is no grant at all
    assertFalse(JDBCStorage.grantedPastTheWindow(2, seconds(12), PROMPT), "a second replay was granted");
    assertFalse(JDBCStorage.grantedPastTheWindow(1, seconds(12), AFTER_LOCK_WAIT), "a bounded wait was granted");
    assertFalse(JDBCStorage.grantedPastTheWindow(1, seconds(12), NONE), "a failure carrying no conflict");
    // every replay the bounds allow past the window is that grant, which is what lets the line name it
    for (int attempt = 1; attempt < 12; attempt++)
    {
      for (Conflict conflict : Conflict.values())
      {
        final boolean pastTheWindow = JDBCStorage.replayableWithin(attempt, seconds(11), conflict);
        assertEquals(pastTheWindow, JDBCStorage.grantedPastTheWindow(attempt, seconds(11), conflict),
            "attempt " + attempt + " of a " + conflict + " conflict past the window");
      }
    }
  }
  @DataProvider
@@ -324,9 +363,9 @@
  public void testADroppedConnectionIsReplayedOnlyBeforeTheCommit()
  {
    final SQLException dropped = sql(0, "08006");
    assertEquals(JDBCStorage.replayReason(dropped, POSTGRES, false, false, false),
    assertEquals(replayReason(dropped, POSTGRES, false, false, false),
        "a connection the database dropped");
    assertNull(JDBCStorage.replayReason(dropped, POSTGRES, true, false, false),
    assertNull(replayReason(dropped, POSTGRES, true, false, false),
        "an in doubt transaction was replayed");
  }
@@ -338,10 +377,10 @@
  public void testAConnectionTheDriverClosedIsADroppedOne()
  {
    final SQLException killed = sql(596, "S0001");
    assertNull(JDBCStorage.replayReason(killed, MSSQL, false, false, false), "S0001 was replayed on its own");
    assertEquals(JDBCStorage.replayReason(killed, MSSQL, false, false, true),
    assertNull(replayReason(killed, MSSQL, false, false, false), "S0001 was replayed on its own");
    assertEquals(replayReason(killed, MSSQL, false, false, true),
        "a connection the database dropped");
    assertNull(JDBCStorage.replayReason(killed, MSSQL, true, false, true),
    assertNull(replayReason(killed, MSSQL, true, false, true),
        "an in doubt transaction was replayed");
  }
@@ -354,9 +393,9 @@
  @Test
  public void testAnAttemptThatCommittedPartOfItsWorkIsNotReplayed()
  {
    assertNull(JDBCStorage.replayReason(sql(0, "40001"), POSTGRES, false, true, false), "a conflict was replayed");
    assertNull(JDBCStorage.replayReason(sql(0, "08006"), POSTGRES, false, true, false), "a drop was replayed");
    assertNull(JDBCStorage.replayReason(sql(596, "S0001"), MSSQL, false, true, true), "a drop was replayed");
    assertNull(replayReason(sql(0, "40001"), POSTGRES, false, true, false), "a conflict was replayed");
    assertNull(replayReason(sql(0, "08006"), POSTGRES, false, true, false), "a drop was replayed");
    assertNull(replayReason(sql(596, "S0001"), MSSQL, false, true, true), "a drop was replayed");
  }
  /**
@@ -370,8 +409,8 @@
  public void testAConflictIsNotReadFromTheReleaseOfTheConnection()
  {
    final SQLException onRelease = suppressing(sql(2627, "23000"), sql(0, "40000"));
    assertFalse(JDBCStorage.isRetryableConflict(onRelease, POSTGRES), "a conflict was read from the release");
    assertNull(JDBCStorage.replayReason(onRelease, POSTGRES, true, false, false),
    assertEquals(JDBCStorage.conflictOf(onRelease, POSTGRES), NONE, "a conflict was read from the release");
    assertNull(replayReason(onRelease, POSTGRES, true, false, false),
        "a transaction the commit left in doubt was replayed");
    // the same shape carrying a drop instead: read, since the release is where a drop is stated at all
@@ -401,16 +440,16 @@
  public void testAConflictIsReplayedFromEitherPhase()
  {
    final SQLException conflict = sql(0, "40001");
    assertEquals(JDBCStorage.replayReason(conflict, POSTGRES, false, false, false), "a conflict");
    assertEquals(JDBCStorage.replayReason(conflict, POSTGRES, true, false, false), "a conflict");
    assertEquals(replayReason(conflict, POSTGRES, false, false, false), "a conflict");
    assertEquals(replayReason(conflict, POSTGRES, true, false, false), "a conflict");
  }
  /** Everything else fails the operation, as it did before either replay existed. */
  @Test
  public void testAFailureOfTheStatementIsNotReplayed()
  {
    assertNull(JDBCStorage.replayReason(sql(2627, "23000"), MSSQL, false, false, false));
    assertNull(JDBCStorage.replayReason(sql(2627, "23000"), MSSQL, true, false, false));
    assertNull(replayReason(sql(2627, "23000"), MSSQL, false, false, false));
    assertNull(replayReason(sql(2627, "23000"), MSSQL, true, false, false));
  }
  /** The delay grows with the attempt, so that the replays outlast a contention lasting more than a few ms. */
@@ -461,6 +500,27 @@
    assertFalse(summary.contains("23000"), summary);
  }
  /**
   * The line names the link the class was decided on, which is not always the first conflict of the chain:
   * {@code conflictOf()} keeps the most specific class it finds, so a wrapper carrying a bare class 40 state is
   * walked past to the lock wait timeout underneath it. Naming the wrapper would print "error 0" for a replay
   * whose whole bound was chosen by the 1205 it never shows.
   */
  @Test
  public void testConflictSummaryNamesTheLinkTheClassWasDecidedOn()
  {
    final SQLException lateUnderAWrapper = sql(0, "40001", sql(1205, "40001"));
    assertEquals(JDBCStorage.conflictOf(lateUnderAWrapper, MYSQL), AFTER_LOCK_WAIT);
    final String summary = JDBCStorage.conflictSummary(lateUnderAWrapper, MYSQL);
    assertTrue(summary.contains("1205"), summary);
    // the same chain under a driver that gives 1205 no such meaning is a prompt conflict, and the first link
    // of it is the one the decision was taken on
    assertEquals(JDBCStorage.conflictOf(sql(0, "40001", sql(1205, "40001")), POSTGRES), PROMPT);
    final String firstLink = JDBCStorage.conflictSummary(sql(0, "40001", sql(1205, "40001")), POSTGRES);
    assertTrue(firstLink.contains("error 0"), firstLink);
  }
  /** A failure carrying no SQLException at all, and a cyclic cause chain, still have to yield something loggable. */
  @Test
  public void testConflictSummaryTerminatesWithoutASQLException()
@@ -549,7 +609,7 @@
    }
    catch (StorageRuntimeException expected)
    {
      assertTrue(JDBCStorage.isRetryableConflict(expected, POSTGRES), "the conflict was not the failure raised");
      assertEquals(JDBCStorage.conflictOf(expected, POSTGRES), PROMPT, "the conflict was not the failure raised");
    }
    assertEquals(attempts.get(), 1, "a transaction that committed part of its work was replayed");
    verify(statements).executeUpdate();
@@ -780,7 +840,7 @@
    }
    catch (StorageRuntimeException expected)
    {
      assertTrue(JDBCStorage.isRetryableConflict(expected, MYSQL), "the conflict was not the failure raised");
      assertEquals(JDBCStorage.conflictOf(expected, MYSQL), PROMPT, "the conflict was not the failure raised");
    }
    assertEquals(attempts.get(), 1, "an attempt that committed part of its work was replayed");
    verify(engineConnection).prepareStatement(startsWith("create index k_"));
@@ -982,6 +1042,17 @@
    }
  }
  /**
   * The two questions {@code write()} asks after a failed attempt, composed here the way it composes them: the
   * conflict class is read off the failure once and handed to the reason, rather than being asked for again.
   */
  private static String replayReason(Throwable failure, String driver, boolean committing, boolean partlyCommitted,
      boolean connectionClosed)
  {
    return JDBCStorage.replayReason(JDBCStorage.conflictOf(failure, driver), failure, committing, partlyCommitted,
        connectionClosed);
  }
  private static SQLException sql(int errorCode, String sqlState)
  {
    return new SQLException("synthetic failure", sqlState, errorCode);
@@ -1000,7 +1071,9 @@
  /**
   * 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.
   * advances a fixed step per attempt - not per read of it - so that the timeline the loop sees depends on what
   * it does rather than on how often it asks the time: a read added anywhere in {@code write()} leaves every row
   * of this provider answering exactly as it does now.
   * <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
@@ -1015,18 +1088,19 @@
      // 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 },
      { "the window bounds the run, not the attempt", 4L, 3 },
      // a step past the window, so only the grant can produce a second attempt: remove it and the run ends on
      // the first. This is the row that pins the grant end to end, and the row above is the one that pins
      // startedAt - at 12 s a per-attempt startedAt also stops at two attempts, and at 4 s the window alone
      // already allows the replay of attempt 1. Neither row is redundant
      { "the first replay is granted past the window", 12L, 2 },
    };
  }
  @Test(dataProvider = "writeRuns")
  public void testWriteDrivesTheRetryLoop(String name, final long stepSeconds, int expectedAttempts,
      int expectedClockReads) throws Exception
  public void testWriteDrivesTheRetryLoop(String name, final long stepSeconds, int expectedAttempts)
      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
@@ -1043,7 +1117,8 @@
      @Override
      long nanoTime()
      {
        return seconds(stepSeconds * clockReads.getAndIncrement());
        // the attempts made are what moves this clock, so the run is the same however often write() reads it
        return seconds(stepSeconds * attempts.get());
      }
    };
    storage.accessMode = AccessMode.READ_WRITE;
@@ -1068,10 +1143,6 @@
    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");
  }
  /** The second failure as the next exception of the first, the way a driver chains the errors of one message. */