Seek the primary key in the SQL Server upsert and retry a transaction conflict - #867
Conversation
… table The MSSQL driver binds setString parameters as NVARCHAR. Under the server's SQL_Latin1_General_CP1_CI_AS collation, comparing the char(128) h column against an NVARCHAR value converts the column rather than the value, so no statement could seek the primary key: every read, delete and upsert scanned the whole table. The upsert runs that scan under WITH (HOLDLOCK, UPDLOCK), which range-locks the entire table instead of the single key being written - the lock footprint behind the intermittent "Transaction (Process ID N) was deadlocked on lock resources" failures of MsSqlTestCase#test_issue_496_2. Casting the parameter back to char(128) keeps the comparison seekable. Verified against mssql/server:2019-CU30 with driver 13.4.0: the MERGE plan goes from Clustered Index Scan (no seek predicate, CONVERT_IMPLICIT on the column) to Clustered Index Seek, and eight threads writing distinct keys in a 2000-row table finish in 3.7 s instead of 20.1 s. Other drivers keep the plain "?" placeholder, so their SQL is unchanged.
maximthomas
left a comment
There was a problem hiding this comment.
The change is correct and it works: binding h as cast(? as char(128)) turns the SQL Server plan from a clustered-index scan into a seek. Measured on mssql/server:2019-CU30, collation SQL_Latin1_General_CP1_CI_AS, mssql-jdbc 13.4.0:
- Fixes the flake. 8 threads × 1023 iterations on one key, table recreated each round: 101/330 rounds failed on master (all error 1205 / SQLState 40001), 0/630 with the cast.
- 19× faster on a many-distinct-keys workload: 98.5 s → 5.2 s.
No blocker found. key2hash zero-pads (128 chars over 200,004 measured inputs incl. empty and 1 MiB keys), no cast site ever binds a prefix, placeholder/setter counts align, there is no statement cache, and read/write parity holds across six collations in both directions.
Requesting changes for one regression the PR introduces and its fix.
New gap-lock deadlock during online bulk load (major)
The old plan held two lock resources; the new one holds one — that is the fix. But on the NOT MATCHED path the seek still takes RangeS-U on the next existing key, i.e. the gap:
empty table, after SELECT + MERGE in one txn
no cast: KEY RangeS-U (ffffffffffff) + KEY X (5eaf8eac1132) <- 2 resources, cycles
with cast: KEY X (5eaf8eac1132) <- 1 resource, cannot cycle
table with rows, NOT MATCHED path
with cast: KEY X (new key) + KEY RangeS-U (next existing key) <- shared gap resource
RangeS-U is self-incompatible, so two transactions inserting distinct new keys that land in the same gap block each other. Because h is SHA-512, index order is a random permutation of logical key order, which defeats the ascending-key-order discipline IndexBuffer and EntryContainer deliberately maintain (opendj-server-legacy/src/main/java/org/opends/server/backends/pluggable/IndexBuffer.java:69-83).
Measured, 2 writers × 10 new keys per txn into one tree, ascending logical order:
| pre-existing rows | 1 | 2 | 5 | 20 | 100 | 500 |
|---|---|---|---|---|---|---|
| with cast | 4/10 | 6/10 | 6/10 | 6/10 | 2/10 | 0/10 |
| master | 0/10 | 0/10 | 0/10 | 0/10 | 0/10 | — |
1 new key per tree per txn → 0/30 (a single insert cannot form a same-table cycle).
Exposure is bounded but real: online initial population — parallel ldapmodify -a, or multi-threaded replication replay into an empty backend — hits five or six small trees at once (objectClass.<eq>, and the cn/sn/givenName/mail/telephoneNumber substring trees), so roughly the first ~100 entries are exposed before the trees pass 500 rows. Offline import-ldif and replication total update bypass this (they go through the importer, not addEntry). Permanent residual: member/uniqueMember equality in deployments whose distinct membership stays under a few hundred.
Steady state is unaffected — every permanently-small tree saturates and takes the MATCHED path (singleton X, no gap lock). id2childrenCount sits at ~32 rows forever on a flat DIT and writes 2 keys/txn, but both are MATCHED after each thread's first add.
With no retry in place (below), each of these surfaces as a failed LDAP ADD.
JDBCStorage.write() does not retry, violating its own SPI contract (major)
opendj-server-legacy/src/main/java/org/opends/server/backends/jdbc/JDBCStorage.java:181-193 rolls back and rethrows:
public void write(WriteOperation writeOperation) throws Exception {
try (final Connection con=getConnection()) {
try {
writeOperation.run(new WriteableTransactionTransactionImpl(con));
con.commit();
} catch (Exception e) {
try { con.rollback(); } catch (SQLException ex) {}
throw e; // no classification, no retry
}
}
}The SPI already requires otherwise:
opendj-server-legacy/src/main/java/org/opends/server/backends/pluggable/spi/Storage.java:72-74— "implementations must ensure the write operation is retried until it succeeds"opendj-server-legacy/src/main/java/org/opends/server/backends/pluggable/spi/WriteOperation.java:25-26— "Implementation must be idempotent since operation might be retried"
The precedent is in-repo: opendj-server-legacy/src/main/java/org/opends/server/backends/pdb/PDBStorage.java:628-660 loops on the engine's conflict exception with jittered backoff. The hot paths are already replayable by design — addEntry allocates the entry ID outside the lambda (EntryContainer.java:1504), and EntryContainer.java:1529 says so explicitly: "No need to call indexBuffer.reset() since IndexBuffer content will be the same for each retry attempt". The connection survives a 1205: CachedConnection.close() rolls back and returns it to the pool, never closing it.
Suggested shape (~30-40 lines, mirror it in read() too):
for (int attempt = 1; ; attempt++) {
try { /* existing body */ return; }
catch (Exception e) {
if (attempt >= MAX_RETRIES || !isRetryableConflict(e)) throw e;
logger.warn(...);
Thread.sleep((long) (Math.random() * MAX_SLEEP_ON_RETRY_MS));
}
}
// walk the cause chain (~10 hops); BOTH arms are required
static boolean isRetryableConflict(Throwable t) {
for (; t != null; t = t.getCause())
if (t instanceof SQLException e)
return e.getErrorCode() == 1205 || String.valueOf(e.getSQLState()).startsWith("40");
return false;
}Both arms matter: the xopenStates connection property makes mssql-jdbc report 1205 as 42000 instead of 40001, while in MySQL error 1205 is lock-wait-timeout — a different condition. startsWith("40") also covers Postgres 40P01 and MySQL/H2 40001. Please bound the loop rather than copying PDB's unbounded for(;;), and log each retry so the residual rate stays observable.
Note three callers that are not replayable — RootContainer.open() (RootContainer.java:135), BackendImpl.applyConfigurationChange() (BackendImpl.java:856, where replay silently skips re-registration), and the index-delete config listeners (EntryContainer.java:242, :324). All are single-threaded admin/startup paths, none is this deadlock class, and all are already exposed to PDB's existing retry — pre-existing, worth a separate ~6-line idempotence fix, not a reason to hold this up.
Deadlocks reach the client as an opaque error (minor)
opendj-server-legacy/src/main/java/org/opends/server/backends/jdbc/JDBCStorage.java:377 wraps in a plain RuntimeException, unlike delete() (:468) and read() (:246) beside it, which both use StorageRuntimeException:
} catch (SQLException e) {
throw new RuntimeException(e); // -> should be StorageRuntimeException
}Because of that, EntryContainer.addEntry's pass-through catch (StorageRuntimeException | ...) at EntryContainer.java:1565-1568 misses it, and every deadlock becomes DirectoryException(ERR_UNCHECKED_EXCEPTION) — opaque to the client and to any future retry predicate. One-word fix.
Nits
- Collation-conditional win: under Windows collations (
Latin1_General_BIN2,_UTF8,Japanese_CI_AS,Turkish_CI_AS,Latin1_General_CS_AS) the uncast query already seeks — the cast changes nothing there. It matters under SQL collations such asSQL_Latin1_General_CP1_CI_AS, which is the testcontainers/CI default. The javadoc mentions this in passing; the commit message presents the win unconditionally. - Cited benchmark doesn't demonstrate the deadlock claim: 8 threads on distinct keys over a 2000-row table measures throughput, and the PR reports 0 deadlocks either way. The deadlock fix is real, but the evidence for it is the lock footprint (2 resources → 1), not that benchmark. On the one-row flake the cast gives no speedup at all — scanning one row costs what seeking it does.
- Driver-agnostic alternative:
statement.setObject(1, hash, java.sql.Types.CHAR)gives the same non-Unicode binding without building driver-specific SQL text, and would also cover the Oracle branch (JDBCStorage.java:416), which has the sameh char(128)column bound viasetString. - Test coverage: the JDBC suite has no concurrent-writer test, and
test_issue_496_2hammers a single key — the MATCHED path — so it structurally cannot detect the new gap-collision path. A cheap unit test of the retry predicate against synthetic nestedSQLException(msg, "40001", 1205)needs no container. - Leftover bare binds:
insert()(:434) andupdate()(:445) still useh=?. Verified unreachable on SQL Server (only callable from the ANSIelsebranch at:429), so not a bug — just noting it was checked.
Storage.write() requires an implementation to retry a rolled back operation until it succeeds, and WriteOperation is documented as idempotent for exactly that reason; PDBStorage already loops on the conflict exception of its own engine, while JDBCStorage rolled back and rethrew. A SQL Server deadlock (error 1205, "Rerun the transaction") therefore reached the client as a failed operation. read() and write() now replay the operation up to 10 times, with the randomized delay PDBStorage uses, when the failure carries a transaction conflict anywhere in its cause chain. The loop is bounded, unlike PDBStorage: the database may be shared with writers outside this server, so a conflict is not guaranteed to clear. Both the vendor error number and the SQLState are examined - the xopenStates property makes the SQL Server driver report 1205 as 42000 rather than 40001, and the other engines carry the conflict in the standard class 40 states under vendor numbers of their own. Every retry is logged so that the residual conflict rate stays observable. put() now throws StorageRuntimeException, like read() and delete() beside it: EntryContainer passes that type through unchanged, while any other runtime exception became an opaque ERR_UNCHECKED_EXCEPTION before it could be classified as a conflict. The two index config delete listeners of EntryContainer tolerate a replay, their map removal no longer dereferencing a null on the second attempt.
|
Thanks — the gap-lock analysis is the part I had missed, and it is what ties the two halves together. Addressed in ea4a361; the PR description is updated accordingly. New gap-lock deadlock during online bulk loadAccepted. What convinced me is the direction of your measurement: master takes one coarse resource, so a second writer merely queues — a convoy cannot cycle. The seek replaces it with fine-grained resources, and two writers inserting distinct new keys into the same gap can then hold what the other needs. So the cast does not simply shrink the conflict window, it trades a serialization for a cycle on the NOT MATCHED path of a small tree. That makes it a reason to land the retry with the cast rather than after it, which is what this push does. I have added the trade-off to the PR description explicitly, so it is not implied by the plan change alone.
|
maximthomas
left a comment
There was a problem hiding this comment.
The cast(? as char(128)) seek fix looks right: key2hash is always a 128-char SHA-512 hex string, so the cast neither truncates nor pads, and hashParam(con) is only ever handed a CachedConnection. The write() retry is correct and welcome. Three points on the rest.
For the record on read(): Storage.java:58-60 does mandate read retry ("implementations must ensure the read operation is retried until it succeeds"), so the loop itself conforms to the contract — the problem is that two read callers are not idempotent.
Replaying read() duplicates export output (major)
ExportJob runs the whole export inside storage.read(...), and its try/catch sits outside that call, so it cannot stop a replay:
// opendj-server-legacy/src/main/java/org/opends/server/backends/pluggable/ExportJob.java:114
rootContainer.getStorage().read(new ReadOperation<Void>() { ... exportContainer(txn, exportContainer); ... });
...
catch (Exception e) { throw new StorageRuntimeException(e); } // outside read(), cannot stop the replayIn exportContainer, while (cursor.next()) (:177) has no swallowing catch — the two inner catch (Exception) blocks wrap only new EntryID(key) and entryFromDatabase — while entry.toLDIF(exportConfig) (:227) has already written entries 1..N-1. CursorImpl.next() -> fetchBatch throws StorageRuntimeException(SQLException) with the cause intact, so a class-40/1205 failure at row N replays the whole export. LDIFExportConfig creates the writer once, so OVERWRITE truncates only on attempt 1 and the replay appends: a duplicate-bearing LDIF reported as success. Before this commit the same conflict gave TaskState.STOPPED_BY_ERROR and a visibly truncated file.
Reachable online: ExportTask.java:363 takes only acquireSharedLock, the running server itself holds a shared lock, and JDBCStorage has no exclusivity at all — no StorageInUseException, no file lock, unlike PDB/JE. Replication total update exports the same way (LDAPReplicationDomain.java:3460).
VerifyJob is the same shape: keyCount (:75) and attrIndexList (:103) are instance fields never reset per attempt, so a replay yields keyCount ~ 2 x storedEntryCount and a spurious ERR_VERIFY_WRONG_ENTRY_COUNT (:394-397) on a healthy backend — which verify-index --countErrors returns as its exit code.
Simplest fix: retry write() only, or refuse to replay a read once its body has emitted output.
Worth knowing: the online LDAP search path is not affected, but only by accident. EntryContainer.java:1280 and DN2URI.java:639 swallow storage failures, and ID2Entry.java:489 builds a causeless DirectoryException, so isRetryableConflict can never see the SQLException. Giving that exception its cause, or turning either swallow into a rethrow, would immediately open a re-send hole into live searches.
Oracle conflicts are not classified (major)
// opendj-server-legacy/src/main/java/org/opends/server/backends/jdbc/JDBCStorage.java:259
if (e.getErrorCode()==ERROR_DEADLOCK_VICTIM || String.valueOf(e.getSQLState()).startsWith("40")) {Oracle is shipped (ojdbc8 is a compile-scope dependency, packaged into lib/) and exercised (OracleTestCase, testcontainers, run under -P precommit). Per the driver's own oracle/jdbc/driver/errorMap.xml:
| Oracle error | errorCode | SQLState | matched? |
|---|---|---|---|
| ORA-00060 deadlock detected | 60 | 61000 (range 50-68) | no |
| ORA-01205 not a data file (fatal) | 1205 | 64000 (range 1100-1250) | yes |
The only class-40 entry in the entire file is ORA-02091/02092. So an Oracle deadlock still fails the operation — the bug this commit exists to fix — while a fatal media error gets 9 replays, 9 WARN stack traces and ~225 ms of added latency before the same error surfaces. JDBCStorageRetryTest.failures() has mssql/postgres/mysql rows and no Oracle row.
Suggest keying the vendor error numbers off the driver, as getTableDialect already does. Two side notes: the javadoc's xopenStates justification for the vendor-independent 1205 match describes a property nothing in this repo sets, and it credits H2, which is not a dependency here at all.
Replayed index delete reports SUCCESS (minor)
attrIndexMap.remove(...) is the first statement of the replayed body, so on attempt 2 the guard skips the delete, the write commits empty, and applyConfigurationDelete returns a default ConfigChangeResult — ResultCode.SUCCESS — for work that did not happen. Attempts 2..10 can never complete this operation.
It bites harder on PDB than on JDBC: removeTree is MVCC-versioned, so a rollback leaves the index trees and their TRUSTED state records fully intact; re-adding the index later has DefaultIndex.afterOpen read that surviving record, mark an empty index trusted, and skip NOTE_INDEX_ADD_REQUIRES_REBUILD — silently incomplete search results.
Minor rather than blocking because the old code was also broken here (attempt 2 threw an NPE), and ConfigurationHandler.deleteEntry deletes and persists the config entry before the listener runs either way — so the on-disk state is unchanged and only the error signal is lost.
Keep the null check: it fixes a real pre-existing NPE, since applyConfigurationAdd can fail after the config entry is persisted but before attrIndexMap.put. Just hoist the mutation out of the replayed body:
// opendj-server-legacy/src/main/java/org/opends/server/backends/pluggable/EntryContainer.java:242
final AttributeIndex index = attrIndexMap.remove(cfg.getAttribute());
attrCryptoMap.remove(cfg.getAttribute());
if (index != null)
{
storage.write(new WriteOperation()
{
@Override
public void run(WriteableTransaction txn) throws Exception
{
index.closeAndDelete(txn);
}
});
}The replay is then idempotent: deleteTree is isExistsTable-guarded, state.deleteRecord on a missing row returns false without throwing, and close() twice is a no-op. The vlvIndexMap listener just below needs the same treatment.
Nits
- Interrupt during the backoff discards the real failure (
opendj-server-legacy/src/main/java/org/opends/server/backends/jdbc/JDBCStorage.java:237):Thread.sleepclears the interrupt flag and throws, soretryOnConflictpropagatesInterruptedExceptionin place of the SQL failure being retried, and downstreamThread.interrupted()seesfalse. Restore the flag and rethrow the originalewith the interrupt as a suppressed exception. con.close()is inside the retried region (JDBCStorage.java:188): thecatchis attached to the try-with-resources, so it also covers the implicit close — andCachedConnection.close()callsrollback(). A class-40SQLExceptionfrom that rollback replays an already-completed operation. An innertryaroundreadOperation.run(...)closes this, and keepsgetConnection()failures out of the retry budget too.- Duplicate response controls on replay:
addResponseControlandaddAdditionalLogItemonly append to lists, so a pre-send search replay can emit twoServerSideSortResponseControls or a duplicateunindexedlog item. - Flat backoff: uniform 0-50 ms with no growth, so all 9 replays finish within ~250 ms on average — unlikely to outlast sustained contention.
… driver read() no longer replays a rolled back operation. Storage asks an implementation to retry a read until it succeeds, but two of the read operations of this server are not idempotent: ExportJob runs the whole export inside a single read and its LDIF writer is opened once, so a replay appends the entries already written instead of truncating the file, and VerifyJob accumulates its counters in instance fields that no attempt resets, so a replay reports twice the entry count of the backend. Both are reachable while the server is online, since an export holds no more than a shared backend lock. A conflict fails the read again, exactly as it did before this branch. The vendor error numbers are now keyed off the driver, the way getTableDialect keys the column types. They cannot be matched driver-independently: Oracle reports a deadlock as ORA-00060 with SQLState 61000, which no class 40 check covers, and gives 1205 to a fatal "not a data file" error, which was replayed nine times for nothing, while 1205 is exactly the deadlock victim of SQL Server and the lock wait timeout of MySQL. The two index config delete listeners remove the index from their map before the write rather than inside it: left inside, the second attempt found nothing to delete and committed an empty transaction, reporting success for work that did not happen. Three corrections to the retry itself. An interrupt during the backoff now restores the flag and rethrows the failure being replayed, with the InterruptedException suppressed into it, instead of replacing it. A failure of getConnection() or of the implicit close(), which rolls back and returns the connection to the pool, leaves the loop, so a completed write is never replayed because releasing its connection failed. And the delay doubles from 50 ms up to a second instead of staying uniform under 50 ms.
|
All three land, and the read retry goes away rather than gets patched. Pushed in bc21fa4; the PR description is updated accordingly. Replaying
|
maximthomas
left a comment
There was a problem hiding this comment.
The cast(? as char(128)) half is solid — key2hash always yields exactly 128 hex chars, all five cast sites bind a complete hash, non-Microsoft SQL text is byte-identical, and the measured plan change (scan → seek) is real. The retry loop's mechanics are also right: the e != failure identity check correctly keeps getConnection()/close() failures out of the replayed region, and the cause-chain walk is cycle-bounded. Splitting the read-replay problem out to #870/#871 is clean.
No blockers or majors. Four minor items below, all cheap.
Retry loop has no wall-clock bound (minor)
MAX_RETRIES bounds attempts, not time. That is fine for a deadlock, which every engine reports in well under a second, but not for a conflict that is slow to report. MySQL surfaces ER_LOCK_WAIT_TIMEOUT only after innodb_lock_wait_timeout (50 s by default; nothing in-tree overrides it), so 10 attempts can park a worker thread for ~505 s where master released it at 50 s.
This is not a merge blocker — MySQL is the only engine affected, and it is also the only one that had a bound at all (SQL Server lockTimeout=-1, Oracle has no row-lock timeout, PostgreSQL lock_timeout=0 all park a worker indefinitely today). For a holder lasting 50–505 s the retry actually wins, turning a hard failure into a success. Only past ~505 s is it a pure loss. But nothing else caps it: there is no setQueryTimeout anywhere under opendj-server-legacy/src/main/java/org/opends/server/backends/, all driver timeouts default to 0/-1, and ds-cfg-max-blocked-write-time-limit governs client socket writes only.
A deadline also discriminates correctly — fast deadlocks keep their full attempt budget, a 50 s timeout blows it on attempt 1:
/**
* Wall-clock budget the retry loop may spend, in nanoseconds. Checked between attempts, so an attempt already
* running is never interrupted: the loop returns after at most this window plus one attempt. It bounds the
* conflicts that are slow to report - MySQL reports ER_LOCK_WAIT_TIMEOUT only after innodb_lock_wait_timeout,
* 50 s by default, so 10 attempts would park a worker thread for eight minutes - while leaving the full attempt
* budget to the deadlocks this retry exists for, which every engine reports in well under a second.
*/
private static final long MAX_RETRY_WINDOW_NANOS = 10_000L * 1_000_000L; public void write(WriteOperation writeOperation) throws Exception {
final long giveUpAt = System.nanoTime() + MAX_RETRY_WINDOW_NANOS;
for (int attempt=1;;attempt++) {
// ... unchanged ...
if (attempt>=MAX_RETRIES || System.nanoTime()-giveUpAt >= 0 || !isRetryableConflict(failure,driver)) {
throw failure;
}System.nanoTime()-giveUpAt >= 0 is the overflow-safe form; no new imports needed.
The MySQL branch is dead code, and documents a SQLState the driver cannot emit (minor)
opendj-server-legacy/src/main/java/org/opends/server/backends/jdbc/JDBCStorage.java:318-319
Connector/J overrides ER_LOCK_WAIT_TIMEOUT's server-side HY000 to 40001 (a "Manual override" for Bug#16634180, applied unconditionally in NativeProtocol, present since 5.1.49). Verified by reflection against the exact compile-scope dependency, com.mysql:mysql-connector-j:9.2.0:
1205 (ER_LOCK_WAIT_TIMEOUT) -> 40001 1206 (ER_LOCK_TABLE_FULL) -> HY000
1213 (ER_LOCK_DEADLOCK) -> 40001 1062 (ER_DUP_ENTRY) -> 23000
So startsWith("40") at :310 matches first and the mysql branch never runs. Two knock-on corrections:
- the javadoc at
:65and:296-297says MySQL reports 1205 "with SQLState HY000" — it does not; opendj-server-legacy/src/test/java/org/opends/server/backends/jdbc/JDBCStorageRetryTest.java:73and:96assertsql(1205, "HY000"), a shape the driver cannot produce. Those rows pass only because the dead branch catches them. They should besql(1205, "40001"), which also makes:96("unknown driver") flip totrue— correctly, since class 40 is driver-independent.
Note this means MySQL lock-wait timeouts are retried via :310 regardless, so deleting the branch is a behavioural no-op — it is the deadline above that changes behaviour.
Replayed index add re-registers config change listeners (minor)
opendj-server-legacy/src/main/java/org/opends/server/backends/pluggable/EntryContainer.java — the two index delete listeners were made replay-safe; the two add listeners were not.
VLVIndex's constructor ends with this.config.addChangeListener(this) (VLVIndex.java:144) and is called inside the lambda, so each attempt builds and registers another instance while only the last reaches vlvIndexMap. There is no dedup anywhere: ServerManagedObject.registerChangeListener wraps a fresh adaptor per call, the store is a CopyOnWriteArrayList with plain add(), and neither adaptor overrides equals/hashCode. The orphans are never closed, so they stay registered for the process lifetime and every later VLV config change is applied N times.
Reachability is narrow — in both add paths every deadlock-prone statement (the state-table merge under HOLDLOCK, UPDLOCK, the id2entry scan) runs before the registration, so a duplicate needs the conflict to land in the trailing catalog/DDL window, i.e. concurrent DDL. And the effect is benign rather than corrupting: AttributeIndex.applyConfigurationChange is synchronized and converges after invocation 1 (removedIndexes/addedIndexes are both empty from invocation 2 on), so there is no delete-and-recreate race. What is worth fixing is that on a successful retry dsconfig reports SUCCESS while the orphans leak, where master failed loudly.
For the attribute path one line suffices, since deregisterChangeListener removes every adaptor wrapping the listener (so it is a no-op on attempt 1):
// close() removes every adaptor registered for this index, so a replayed attempt does not add a second one
index.close();
index.open(txn, true);For VLV the previous attempt's instance has to be closed before the next is built — same shape as the hoisting already done for the delete listeners.
No concurrent-writer test on distinct keys (minor)
This is the one gap the PR's own "On the lock footprint" section leaves open. The new gap-lock path needs two or more new keys inserted into the same table per transaction to form a cycle — a single shared gap is one resource and can only block. Nothing in the suite exercises that:
PluggableBackendImplTestCase.java:1275-1336— 8 threads × 1023 iterations, all on the literal key"key", i.e. one resource and the MATCHED path;opendj-server-legacy/src/test/java/org/opends/server/backends/jdbc/TestCase.java— all three tests single-threaded;ID2ChildrenCountTestis concurrent but bindsPDBStorage, never JDBC;JDBCStorageRetryTestis synthetic and threadless.
A test in jdbc/TestCase.java (so all four engines inherit it) seeding ~10 rows then running N≥2 threads × M rounds, each writing ≥2 distinct new keys per storage.write, asserting nothing escapes — that is the harness that produced the 4–6/10 numbers, and it would regression-guard both halves of this PR.
Nits
- "Left out" overstates reachability: it says these paths are ones "that the conflict class handled here cannot reach". That is unproven, and it sits awkwardly next to the shared-database premise used to justify bounding the loop two paragraphs earlier.
BackendImpl.applyConfigurationChangeandRootContainer.open()are both genuinely non-idempotent — worth saying so plainly instead. Neither is a blocker: a replay ofapplyConfigurationChangethrows atderegisterBaseDNbefore issuing any SQL, so it destroys nothing master didn't; andERR_ENTRY_CONTAINER_ALREADY_REGISTEREDis unreachable with a single base DN, which covers the defaultuserRootand CI. ccrmessages accumulate per attempt: both add listeners callccr.addMessage(NOTE_INDEX_ADD_REQUIRES_REBUILD...)inside the lambda, sodsconfigcan print it up to 10 times. Moving it out with the map puts fixes it.- Retry logging volume:
JDBCStorage.java:258logs a full single-line stack trace at WARN per retry. During the initial-population window this PR expects to conflict, one add can emit 9 of them, which reads as failure to monitoring. Attempt count + SQLState/error number at WARN, stack trace at debug. - Backoff ignores cancellation: the loop never consults
checkIfCanceled, andapplyConfigurationDeleteholds the exclusiveEntryContainer.this.lock()— which drains all in-flight shared access — across the whole ~5.5 s of it. - SQLState
40003: the blanket class-40 test also matches "statement completion unknown". Acon.commit()that fails that way is inside the retriedtry, so it replays, andaddEntry's replay then returnsENTRY_ALREADY_EXISTSfor an add that succeeded. Narrowing the blanket match to40001/40P01closes it. - Collation-conditional win: worth keeping the note that under Windows collations (
Latin1_General_BIN2,_UTF8,Japanese_CI_AS,Turkish_CI_AS,Latin1_General_CS_AS) the uncast query already seeks and the cast is a no-op. The description does say this; the commit message does not. - Merge interaction: #866 also modifies
JDBCStorage.java. Expect a conflict for whichever lands second.
Three pre-existing bugs surfaced while reviewing this. None belong to this PR, but each is worth its own issue:
PersistentCompressedSchema.java:59,61buildsstatic final TreeName("compressed_schema", ...)with a literal in the baseDN slot — no backend qualifier — andgetTableNameissha224(TreeName). Every JDBC backend sharing a database URL therefore shares the same two tables.export-ldif,verify-indexandbackendstatcannot open a JDBC backend at all:BackendImpl.java:952usesAccessMode.READ_ONLY,RootContainer.openalways goes throughstorage.write(...), andWriteableTransactionTransactionImpl's constructor throwsReadOnlyStorageExceptionwhen the mode is not writeable (JDBCStorage.java:260-264).CachedConnection.java:99-105—getConnectionrecurses unboundedly with a doubling wait whenDriverManager.getConnectionfails, so pool exhaustion has no bound.
…from registering a second listener MAX_RETRIES bounded the attempts but not the time they take, and an attempt is not guaranteed to be short. MySQL reports a lock wait timeout only after innodb_lock_wait_timeout, 50 s by default and overridden nowhere in this tree, so ten attempts parked a worker thread for eight minutes where master released it after 50 s. A ten second wall-clock window now bounds the loop as well. It is checked between attempts, so an attempt already running is never interrupted, and a deadlock - which every engine reports in well under a second - keeps its full attempt budget, while a conflict that slow spends the whole window in one attempt and fails exactly as it did before this branch. The MySQL error number is gone, because the driver never reaches it. Connector/J replaces the server side HY000 of both ER_LOCK_WAIT_TIMEOUT and ER_LOCK_DEADLOCK with 40001, an override applied unconditionally in NativeProtocol, so the class 40 check matched first and the branch was dead. Verified against the compile scope dependency, mysql-connector-j 9.2.0: of class 40 that driver emits only 40000, for the group replication rollback of error 3101, and 40001, for errors 1205 and 1213. The javadoc and the two test rows that asserted 1205 with HY000 described a shape the driver cannot produce and are corrected. A MySQL lock wait timeout is still replayed, by its state rather than by its number. Two class 40 states are excluded from the blanket match. 40003 leaves the outcome of the transaction unknown, so replaying an add that in fact committed would answer the client with "entry already exists", and 40002 is an integrity constraint violation that a replay only hits again. Neither is reachable with the drivers shipped here, so the match is not narrowed to a whitelist instead, which a further engine reporting a conflict of its own would fail. The two index config add listeners no longer register one listener per attempt. AttributeIndex.open() registers the index as a change listener of its configuration and the VLVIndex constructor registers the instance it builds, so a replayed attempt added another while only the last reached the map. Nothing ever closed the orphans, so they stayed registered for the lifetime of the process and every later configuration change was applied once per attempt, while dsconfig reported success. The attribute index is now closed before it is opened, which removes every registration made for it, and the VLV index built by the previous attempt is closed before the next one is built. The message asking for a rebuild moved out of the write for the same reason: it could otherwise be printed ten times. A replay logs one line rather than a stack trace, since a single add can emit nine of them and a trace each time reads as a failure to monitoring. The SQLState and the vendor number identify the conflict; the stack trace moved to the trace level. The concurrent writer test that the lock footprint argument needs is added to the JDBC test case, so all four engines inherit it. It seeds a tree, then has four threads write three distinct new keys each into that tree per transaction - the shape that can cycle on the NOT MATCHED path of the seek, since a single new key takes one gap resource and can only block - and asserts that nothing escapes write() and that no record is lost. For the record on the seek itself, which the first commit of this branch does not say: the plan change is conditional on the collation. Under a SQL collation such as the SQL_Latin1_General_CP1_CI_AS default of the testcontainers image the cast turns a clustered index scan into a seek, while under a Windows collation - Latin1_General_BIN2, _UTF8, Japanese_CI_AS, Turkish_CI_AS, Latin1_General_CS_AS - the uncast query already seeks and the cast is a no-op.
|
All four minors are taken, in bfb8c95; the PR description is updated accordingly. Two of the nits I answered differently than suggested, and one of them is a correction to the review — details below. Retry loop has no wall-clock boundTaken as written: a 10 s window, checked between attempts with the overflow-safe Worth stating the consequence plainly rather than leaving it implied, because it reverses a decision I made two rounds ago: with a 10 s window a MySQL The MySQL branch is dead codeConfirmed independently before deleting it, by reflection against the exact compile-scope dependency: and the override is visible in One departure: I did not flip Replayed index add re-registers config change listenersTaken, both listeners, plus the I verified the mechanism rather than take it on trust: One correction to the reachability estimate, in the direction of it mattering more. For VLV the registration is the last statement of the constructor, and the constructor is not the trailing catalog window: it reads No concurrent-writer test on distinct keysAdded as Nits
The three pre-existing bugs are all real; I confirmed the second down to the code path — |
|
The three pre-existing bugs are filed: #873 (compressed-schema tables shared by every JDBC backend on one database), #874 (offline Two refinements came out of writing them up. For #874 the failure is narrower than "cannot open a JDBC backend at all": |
master added the table stamping of OpenIdentityPlatform#866, which closes the comment connection of a transaction in a finally block, while this branch wrapped the same transaction in a retry loop. The transaction object is now bound per attempt and its stamp session closed with it, so a replay stamps on a session of its own. Both sides also grew a helper returning the driver name behind a connection - driverNameOf() on master, getDriverName() here. Collapsed into master's name, keeping the body of this branch, which tolerates a connection that did not come from the pool. The read() javadoc no longer says that Storage#read asks for a replay: OpenIdentityPlatform#871 turned that contract around on master, and it now forbids one, which is what this implementation already did.
…er, not only by its SQLState, and the rest of what the review found open isConnectionFailure classified a lost connection by SQLState alone, and mssql-jdbc carries none: SQLServerException extends SQLException directly, xopenStates is off by default, and generateStateCode maps neither 596 (session in kill state) nor 3980, 10054, 18456 or 4060 - every one of them comes out as "S"+errorState, measured as S0001. A KILL, a resource governor kill or an availability group transition therefore gave neither the replay nor the distrust, and the window handed out the rest of that generation unvalidated, one failed operation per pooled connection. What the driver does do is close the connection for any error of severity 20 and above, before it throws, so the connection is now asked as well as the failure - while the operation that failed still owns it, since a released one may already be another borrow's. The types the JDBC contract gives a driver to say so are matched too, which is what makes the oracle case robust rather than lucky, and the next-exception and suppressed chains are walked with the causes, the way failureScope already walked both. An attempt that committed part of its own work is no longer replayed at all. openTree, clearTree and deleteTree commit inside WriteOperation.run - and mysql and oracle commit before a DDL statement whether asked to or not - so the attempt no longer rolls back as a whole, while a WriteOperation is only idempotent in the database. RootContainer.open opens and registers the entry containers of every base DN in a single write: replayed after the trees of the first base DN were created and committed, it registers that base DN a second time, fails with ERR_ENTRY_CONTAINER_ALREADY_REGISTERED, masks the failure that caused the replay and leaves the indexes of the previous attempt behind with the configuration listeners their constructors registered. The conflict replay of OpenIdentityPlatform#867 could already reach this, so the rule covers any replay rather than only the drop added here. read() and write() borrow outside their try, so that a connect the pool could not make no longer distrusts the pool: Connector/J reports a server at its connection limit as 08004, which is class 08 like a connection that broke, and every failed borrow re-stamped the distrust - an extra round trip per returning connection against a server already refusing connections. A drop reported by the release of a connection now reaches the pool from write() as well, which returned before the distrust call. The three borrows nothing compensates - open(), removeStorageFiles() and the importer - ask for a connection the pool validates whatever the window says: they issue their statements far from the borrow, and the open issues none at all, so a connection dropped inside the window surfaced out of the rollback that released it, with nothing to replay it and nothing to tell the pool. One round trip on a path taken once per open, per import or per removal. distrustPool merges its reading with max instead of setting an AtomicLong published holding its initial 0, so that two operations reporting a drop at once cannot move the distrust point backwards. The window is clamped to the ttl an idle pooled connection is kept for, and says so once when it is asked for more: a value the unit conversion saturates on would leave every connection trusted for the life of the server. A connection the pool closed under the borrow - the removal listener iterates a weakly consistent view - is no longer handed out on the strength of its last answer. Also: the comment crediting HikariCP's list undercounted what it leaves out, the seeded pool of the tests filled the end production does not return to, and the bound of the walk covers all three chains.
…zer that reaches it, and commit the flag with the statement Three findings of the third review round. warnedOnce sat below aliveBypassNanos, whose initializer reaches warnOnce() through both properties it reads: class variable initializers run in textual order (JLS 12.4.2), so any value worth a log line - a window longer than the ttl, which is the tuning the javadoc of the property invites, or a non-numeric or negative value of either property - left the class uninitializable. The first borrow got an ExceptionInInitializerError and every one after it a causeless NoClassDefFoundError, so no connection could be borrowed and the backend could not open at all. The ttl half of that was a regression against the base branch. openTree() raised partlyCommitted for the whole method, before the catalog read that most often decides no statement is needed. On an existing backend on mysql, oracle and mssql it issues nothing, so the flag took a transaction the engine had rolled back whole out of the replay - the conflict replay of OpenIdentityPlatform#867 included, since replayReason() reads it before it asks anything else. It is raised at each site that actually commits instead, and the create index of postgresql is now guarded by the catalog read the other engines already used: unguarded it commits on every openTree(), which took every write that opens a tree out of the conflict replay on the engine of every default deployment. write() computed the drop flag before the implicit close(), so a drop the release reported - suppressed into the failure being unwound rather than replacing it - was replayed on evidence the pool was never told about. Both loops now report the drop from the inner catch, before the release returns the connection to the head of the pool where a borrow racing the report would be handed it unvalidated; and the rollback that unwinds a failed attempt joins its own failure to the one being unwound rather than dropping it, since on a driver that reports a killed session as a plain vendor error that rollback is the only place the drop is ever stated. Alongside: the classifiers share one walk of the failure, which reads the suppressed exceptions for a question about the connection and not for a question about what the engine did with the transaction - the release runs after the outcome was decided and cannot speak for it, and a class 40 raised there would otherwise re-authorise the replay of a commit left in doubt. The walk of failureScope() is left unbounded, since its verdict weakens under truncation rather than merely going unnoticed. The replay log names the failure the replay was decided on. The distrust point is merged with the overflow safe comparison the rest of the file uses, and the clamp javadoc argues what the code does. CachedConnectionTestCase and JDBCStorageRetryTest, 115 methods, green - the writes now run through JDBCStorage.write() against a stub driver rather than against the classifiers alone. PgSqlTestCase against postgres in docker, 54 methods, green.
Problem
MsSqlTestCase#test_issue_496_2fails intermittently on CI with SQL Server error 1205, most recently in run 31627184500 — the only failing job of that build, 1 failure out of 31844 tests:The upsert already carries
WITH (HOLDLOCK, UPDLOCK)from an earlier deadlock fix, so this is a residual deadlock rather than a missing hint.Root cause
Two independent causes, both addressed here.
1. The primary key could not be sought. The MSSQL driver binds
setStringparameters as NVARCHAR. Under a SQL collation such as theSQL_Latin1_General_CP1_CI_ASdefault of the testcontainers image, comparing thechar(128)hcolumn against an NVARCHAR value converts the column rather than the value, so the primary key cannot be sought — everyread,deleteand upsert scans the whole table. The upsert runs that scan underHOLDLOCK, which range-locks the entire table instead of the single key being written.2. A conflict was never retried.
Storage.write()requires an implementation to "ensure the write operation is retried until it succeeds", andWriteOperationis documented as idempotent for exactly that reason;PDBStorage.write()already loops on the conflict exception of its own engine.JDBCStorage.write()rolled back and rethrew, so a deadlock surfaced as a failed operation — a failed LDAP ADD in production, a failed test on CI — instead of a replay.Fix
char(128)where thehcolumn is compared, so the comparison stays seekable. Other drivers keep the plain?placeholder — their SQL is byte-for-byte unchanged.write(): up to 10 attempts inside a 10 s wall-clock window when the failure carries a transaction conflict anywhere in its cause chain, with a randomized delay doubling from 50 ms up to a second. The window is checked between attempts, so an attempt already running is never interrupted; it bounds the conflicts an engine is slow to report, which an attempt count alone does not — MySQL surfaces a lock wait timeout only afterinnodb_lock_wait_timeout, 50 s by default and overridden nowhere in this tree, so ten attempts would have parked a worker thread for eight minutes where master released it after 50 s. A deadlock, which every engine reports in well under a second, keeps its full attempt budget. Every replay is logged at WARN as one line naming the SQLState and the vendor number, with the stack trace at trace level, so the residual conflict rate stays observable without one add emitting nine stack traces. The loop is bounded, unlike PDBStorage'sfor(;;): the database may be shared with writers outside this server, so a conflict is not guaranteed to clear. Only the operation is replayed — a failure ofgetConnection()or of the implicitclose(), which rolls back and returns the connection to the pool, leaves the loop, so a completed write is never replayed because releasing its connection failed.read()is deliberately not retried, althoughStorage.read()asks for it. The contract's premise is an idempotentReadOperation, and two of this server's read operations are not:ExportJobruns the whole export inside a single read with an LDIF writer opened once, so a replay appends the entries already written instead of truncating the file, andVerifyJobaccumulates its counters in instance fields that no attempt resets, so a replay reports twice the entry count of the backend. Both are reachable online, since an export holds no more than a shared backend lock. A conflict fails the read, exactly as it did before this PR. The same exposure has existed inPDBStorage.read()all along and is recorded separately in PDBStorage.read() may replay a read whose body is not idempotent (export, verify, backendstat) #870.getTableDialectkeys the column types, because the vendor numbers collide across engines: Oracle reports a deadlock as ORA-00060 with SQLState 61000, which no class 40 check covers, and gives 1205 to a fatal "not a data file" error, while 1205 is exactly the deadlock victim of SQL Server. So: Oracle 60, SQL Server 1205, and for everything else the standard class 40 states alone. MySQL needs no number of its own — Connector/J replaces the server-sideHY000of bothER_LOCK_WAIT_TIMEOUT(1205) andER_LOCK_DEADLOCK(1213) with40001, so the class 40 match already covers them. That timeout is not a deadlock, but it is transient in the same way and equally resolved by a replay. Two class 40 states are excluded from the blanket match:40003leaves the outcome of the transaction unknown, so replaying an add that in fact committed would answer the client withENTRY_ALREADY_EXISTS, and40002is an integrity constraint violation a replay only hits again.put()throwsStorageRuntimeException, likeread()anddelete()beside it. With a plainRuntimeException,EntryContainer.addEntryturned every deadlock into an opaqueERR_UNCHECKED_EXCEPTIONbefore it could be classified as a conflict.EntryContainerremove the index from their map before the write rather than inside it. Inside, the second attempt found nothing to delete and committed an empty transaction, reportingSUCCESSfor work that did not happen; before this branch it dereferenced a null instead. The null check stays —applyConfigurationAddcan fail after the config entry was persisted but before the index reached the map.AttributeIndex.open()registers the index as a change listener of its configuration and theVLVIndexconstructor registers the instance it builds, both inside the write. A replayed attempt registered another while only the last instance reached the map, and nothing ever closed the orphans, so they stayed registered for the lifetime of the process and every later configuration change was applied once per attempt — withdsconfigreportingSUCCESS. The attribute index is now closed before it is opened (deregisterChangeListenerremoves every adaptor wrapping the listener, so it is a no-op on the first attempt), and the VLV index built by the previous attempt is closed before the next one is built. The message asking for a rebuild moved out of the write for the same reason: it could otherwise be printed ten times.On the lock footprint
The seek narrows the upsert from a whole-table range lock to the single key being written, which is the point of change 1. It is not free of conflicts: on the NOT MATCHED path the seek still takes
RangeS-Uon the next existing key, so two writers inserting distinct new keys into the same gap of a small tree can cycle where the whole-table lock would merely have made them queue. That window is bounded — small trees during the initial population of a backend — and it is exactly what change 2 covers: a conflict is now replayed rather than propagated. Neither change stands well alone, which is why they land together.TestCase#testConcurrentWritersInsertingDistinctKeysexercises that shape directly, and all four engine suites inherit it: it seeds a tree with 10 rows, then has 4 threads write 3 distinct new keys each into that tree per transaction, 25 rounds apiece. Two or more new keys per transaction is what can form a cycle — a single new key takes one gap resource and can only block. It asserts that nothing escapeswrite()and that no record is lost.Verification
Against
mcr.microsoft.com/mssql/server:2019-CU30-ubuntu-20.04with mssql-jdbc 13.4.0 (same image and driver as CI), replaying the storage access pattern ofupdate():@P0 nvarchar(4000)@P0 nvarchar(4000)MERGEplanCONVERT_IMPLICITon the columnThe plan change is collation-conditional: under Windows collations (
Latin1_General_BIN2,_UTF8,Japanese_CI_AS,Turkish_CI_AS,Latin1_General_CS_AS) the uncast query already seeks and the cast changes nothing. It matters under SQL collations such asSQL_Latin1_General_CP1_CI_AS, which is the testcontainers and CI default.That benchmark measures throughput, not deadlocks — it reports 0 occurrences either way, since it writes distinct keys. The evidence for the deadlock itself is the reduction in lock footprint (whole-table range lock down to a single key) plus the review measurement below; the 1205 could not be reproduced locally on the original one-key workload.
Reported in review, on the same image and collation, hammering a single key with 8 threads and recreating the table each round: 101/330 rounds failed on master (all error 1205 / SQLState 40001), 0/630 with the cast; and 19x faster on a many-distinct-keys workload, 98.5 s -> 5.2 s.
The per-driver classification was checked against
oracle/jdbc/driver/errorMap.xmlof ojdbc8 23.7.0.25.01, the version this build resolves: ORA-00060 falls in the 50-68 range mapped to SQLState 61000, ORA-01205 in the 1100-1250 range mapped to 64000, and ORA-02091/02092 is the only class 40 entry in the whole file.The MySQL mapping was checked against the compile-scope dependency itself,
com.mysql:mysql-connector-j:9.2.0.MysqlErrorNumbers.mysqlToSqlstatemaps 1205 and 1213 to40001, andNativeProtocolapplies that mapping whenever the server reportsHY000. Of class 40 the driver emits only40000(error 3101, the rollback of a group replication conflict) and40001— never40002or40003.JDBCStorageRetryTestcovers the classification against syntheticSQLExceptions — the per-driver error numbers and states including Oracle, the collisions that must not be matched driver-independently, the class 40 states that must not be replayed, the wrapped cause chains, a cyclic cause chain, the summary a replay logs, and the growth of the backoff. 26 cases, no container, 0.6 s.Test runs, all green:
JDBCStorageRetryTestMsSqlTestCaseOracleTestCaseMySqlTestCasePgSqlTestCaseLeft out
RootContainer.open()andBackendImpl.applyConfigurationChange()are genuinely not idempotent under a replay, and are left as they are. Neither is a blocker: a replay ofapplyConfigurationChangethrows atderegisterBaseDNbefore it issues any SQL, so it destroys nothing master did not, andERR_ENTRY_CONTAINER_ALREADY_REGISTEREDis unreachable with a single base DN, which covers the defaultuserRootand CI. Both are single-threaded startup/admin paths, and both were already exposed to the retryPDBStoragehas always had.checkIfCanceledduring its backoff.Storage.write()has no cancellation hook to consult —checkIfCanceledbelongs toOperation— so wiring one through is its own change. The wall-clock window above bounds the worst case that made it worth raising:applyConfigurationDeleteholds the exclusiveEntryContainerlock across the whole loop.PDBStorage.read()keeps replaying a rolled back read, with the export and verify consequences described in PDBStorage.read() may replay a read whose body is not idempotent (export, verify, backendstat) #870. Changing it is not this PR's business, and nothing here makes it worse.