[#877] Bound a statement of the JDBC backend by the class of the work it belongs to - #882
Conversation
|
@maximthomas one commit added since the review was requested — 3da33ea, worth a look before you start rather than after. The socket read timeout armed behind the cancel of a statement was being set unconditionally. It is the cancel's bound plus a margin, so it is the looser of the two by construction, which means a connection that already carried a read timeout of its own had it replaced — with a weaker one — for the duration of every statement. Nothing in this repository sets such a timeout today, but #885 asks for exactly that setting, and it would have been silently ignored while a statement was running, which is when it matters.
Two tests came with it, so The "Two layers" section of the description now says this too. |
maximthomas
left a comment
There was a problem hiding this comment.
Reviewed 58f2874 and 3da33ea. The OPERATION/BULK split is a sound design, and the "only ever tighten" guard in 3da33ea is correct: previous == 0 arms, 0 < previous <= backstop is left alone, previous > backstop is tightened and restored, and the -1 sentinel cannot collide because getNetworkTimeout() is non-negative by contract.
Two issues should be addressed before merge; the rest are minor.
Row transfer runs outside both timeout layers (major)
opendj-server-legacy/src/main/java/org/opends/server/backends/jdbc/JDBCStorage.java:148-163 releases the backstop before the caller reads a single row:
try {
return execution.run(); // returns a live ResultSet
}catch (SQLException e) {
throw timedOut(e, bound, seconds, startedAt);
}finally {
releaseBackstop(statement, backstop); // socket read timeout back to 0
}The drain happens afterwards — read() at :376-378, and fetchBatch() at :658-662 which pulls up to fetchsize (default 1000) rows.
setQueryTimeout covering ResultSet.next() is explicitly optional per the JDBC javadoc ("drivers may also apply this limit to ResultSet methods"). Of the four supported drivers:
- PostgreSQL / MySQL — fully buffered at execute (
setFetchSizeis never called;useCursorFetchdefaults false). Not affected. - Oracle (ojdbc8) —
defaultRowPrefetchis 10 against batches of 1000, andOracleStatement.fetchMoreRowscallsbeginTimeout()only whenserverCursor == true, which is false by default. Roughly 99 of every 100 round trips run with neither timeout armed, plus the LOB round trips forv blob. - SQL Server (mssql-jdbc) —
responseBuffering=adaptiveis the default, andTDSCommand.startResponsecancelsTDSTimeoutTaskright after the firstreadPacket();cancelQueryTimeoutdefaults to-1.
On SQL Server this means #877's own symptom is only nondeterministically fixed: default READ COMMITTED takes shared locks, so a select really does block on a row another session holds, and whether that block lands inside execute() (covered) or after the first 8 KB packet (uncovered) depends on where the locked row sits in the batch. Meanwhile the javadoc at :134-144 states that "A statement of this backend has to end" and that the socket read timeout "ends the wait even when the cancel is not acted upon" — not delivered on half the supported engines. That assurance also discourages the one mitigation that does cover the drain (a connection-level socket timeout), which on Oracle is not even reachable through the URL; it needs oracle.net.READ_TIMEOUT.
Suggested fix: hold the backstop for the statement's life — release it where the ResultSet/statement is closed rather than when executeQuery returns.
positionToLastKey() is bounded as OPERATION on the backend-open path (major)
opendj-server-legacy/src/main/java/org/opends/server/backends/jdbc/JDBCStorage.java:782-784:
public boolean positionToLastKey() {
if (fetchBatch(null,null,0,true,1)) {With no condition this emits select k,v from <table> order by k desc offset ? rows fetch next ? rows only through the single-argument executeResultSet (:108), i.e. OPERATION, 120 s.
It runs on every backend open, unconditionally per base DN:
BackendImpl.java:200 newRootContainer(...) — outside the only try/catch, which starts at :206 and wraps getEntryCount() — → RootContainer.java:225 ec.getHighestEntryID(txn) → EntryContainer.java:660-665 cursor.positionToLastKey() on id2entry.
On SQL Server k is varbinary(max) (:428) and cannot be an index key, as the comment at :478 already notes, so this is a full scan plus a top-1 sort. A large mssql backend that previously opened slowly now fails to open, and the only escape is disabling the bound globally.
This also contradicts the PR's own taxonomy: getRecordCount already uses BULK (:392), whose javadoc reads "a whole table at once" (:88) — which is exactly what an unfiltered order by k desc is.
One line at :658 covers this, positionToIndex, and the mssql first-batch case:
executeResultSet(statement, condition==null ? StatementBound.BULK : StatementBound.OPERATION)Nits
setQueryTimeoutis unguarded (JDBCStorage.java:153): it sits outside anytry, unlikearmBackstop(), which catches and degrades. The JDBC spec allowsSQLFeatureNotSupportedException, and this backend accepts an arbitrary URL with an ANSI fallback dialect — on such a driver every statement now fails where it previously worked.timedOut()misattributes late failures (:224): classification is purely by elapsed time, so a connection reset at 121 s is reported as "raiseorg.openidentityplatform.opendj.jdbc.query.timeout".System.currentTimeMillis()also means an NTP step backwards hides a real timeout and a step forwards manufactures one —System.nanoTime()is the right clock for a duration.backstopWarnedis static (:172): one warning per JVM, shared across instances. With a driver lackingsetNetworkTimeoutit fires once during startup and is then permanently silent; a second JDBC backend never reports it at all.- Two execution sites bypass
bounded()(:410,:484):getMetaData().getTables(...)andgetIndexInfo(...)are unbounded in both phases and run once per tree on every open. The commit message's "all nineteen execution sites" is accurate for those nineteen, but there are 21 places this backend sends work to the database — and the commit names "a table waiting for a metadata lock" as a motivating hazard, which is precisely what these two are exposed to. positionToIndexis O(offset) on every engine (:796):offset ? rows fetch next ?is driven straight from a client-supplied VLV position (VLVIndex.java:701), so a deep VLV request now errors at 120 s instead of answering slowly.BULKdefaults to 0 (:89): one of the three hangs named in the method's own javadoc — a table waiting for a metadata lock — stays unfixed under stock settings, e.g. the MySQLcreate indexinopenTree()(:458). The trade-off is reasonable, but the description reads as if the whole class is closed.ImporterImpl.close()has nofinally(:838):con.commit(); con.close();— and the bulk bound makes this reachable, since a throwingclearTree()closes the importer and a throwingcommit()then skipscon.close(), leaking the connection with its transaction and locks.
…scan of a backend open its own class The review of OpenIdentityPlatform#882 found the bound covering less than its javadoc claims. The rows were read after it was released. bounded() put the socket read timeout back in a finally that runs before the caller has seen a single row, and the transfer is where the wait lives: a driver hands rows over as they are asked for, and setQueryTimeout covering ResultSet.next() is optional in the JDBC contract. PostgreSQL and MySQL buffer a result whole and were never affected, but oracle prefetches ten rows against batches of a thousand and mssql buffers adaptively, so on both of them nearly every round trip of a batch ran with neither layer armed - and on mssql, where a select under READ COMMITTED really does block on a row another session holds, that is the symptom of OpenIdentityPlatform#877 itself. executeResultSet() hands the rows to its caller now instead of returning a live ResultSet, so the transfer, the classification of a failure and the release of the backstop all happen where the statement does. positionToLastKey() was bounded as an operation. It has no key to seek on, so it is an "order by k desc" over the whole table - a scan and a sort of it on mssql, where k is a varbinary(max) that cannot be an index key - and every open of a backend runs it once per base DN, through EntryContainer.getHighestEntryID(), outside the try/catch of BackendImpl.openBackend(). Two minutes there turns a large backend that opens slowly into one that does not open at all. It takes the bulk class now, which fetchBatch() receives from its caller rather than deriving from the shape of the query: the first batch of every cursor carries no condition either, and that one is on a search path and stays an operation, as does the VLV offset of positionToIndex() - a client-driven offset is exactly what has to give the worker thread back. Also from the review: - the catalog lookups of openTree(), getTables() and getIndexInfo(), went through no bound at all. DatabaseMetaData takes no query timeout, so they get the socket read timeout alone, as the operations they are: they run once per tree on every open, behind the same locks as the create table they guard; - setQueryTimeout() was called outside any try. The contract allows SQLFeatureNotSupportedException and this backend takes whatever URL a deployment configures, so such a driver now degrades to the backstop with one warning instead of failing every statement it is given; - the bound was measured on the wall clock, which a step of it could lengthen or shorten. It is the monotonic clock now; - the warning about a driver that will not take a backstop was static: the first backend to hit it silenced it for every other one in the JVM. It is per storage, and the same is true of the new one above it; - ImporterImpl.close() ran "con.commit(); con.close();" with nothing between them, so a commit that throws left the connection out of the pool for good, holding the transaction and the locks of that import - and the bulk bound makes that reachable, since a clearTree() that gives up closes the importer on its way out. The connection goes back whatever the commit does, and the storage this importer opened is closed whatever the connection does; - seconds() said a value that is not a number leaves a class unbounded. Integer.getInteger() falls back to its default instead, which is what the test asserted all along; the javadoc, the test name and the description of the bulk class shipping unbounded say so now. JDBCStatementBoundTestCase covers the rows being read while the bound is still armed and a failure during that transfer being measured against it, a driver without a query timeout still running under the backstop, a catalog lookup being bounded, and the class of both kinds of cursor batch - 15 tests, no database, 3 s. PgSql 39/39, MySql 39/39, MsSql 39/39, Oracle 39/39 and the JDBC EncryptedTestCase 34/34 pass with no skips.
|
Thank you — both major findings were real, and every line reference in the review checked out. All of it is addressed in Row transfer runs outside both timeout layersConfirmed and fixed. Your driver survey matches what is in the file:
|
…by the class of its call site Not one statement of this backend was given a setQueryTimeout, so a row locked by an unrelated session, a table waiting for a metadata lock or a database that stopped answering mid-query parked the worker thread that issued it for good - the half of OpenIdentityPlatform#872 that lives behind a successful login, where the bound on establishing a connection cannot reach. The bound goes on the statement rather than on the session: a pooled connection cannot carry a session setting, since CachedConnection.close() only rolls back and a statement_timeout of one operation would then apply to whoever borrows the connection next. All nineteen execution sites already went through execute()/executeResultSet(), so that is where it is applied, by the class of the call site - one value cannot serve both. An entry read is a single row of an index and is bounded by org.openidentityplatform.opendj.jdbc.query.timeout (120 s by default), while the count of a tree, the delete that empties one before an import, create index and drop table are a scan or a rewrite of a whole table: they take minutes on a populated backend and keep a bound of their own, org.openidentityplatform.opendj.jdbc.bulk.timeout, unbounded by default. A backend start counts its entries and an import clears every tree, so a single default would have broken both. The bound is applied in two layers, because the first one is not answered everywhere: setQueryTimeout cancels the statement and keeps the connection, and a socket read timeout armed for the duration of the statement ends the wait even when the cancel is not acted upon. Oracle needs it: a session blocked in a row-lock enqueue does not process the break its driver sends, and the container suite caught the statement parked in a socket read with its timeout armed and never arriving. Reaching the second layer costs the connection, which is the price of a wait the database was not going to end. A failure that arrives before the bound is passed through untouched, so a lock wait reported in class 40 stays the conflict a caller can replay; one that arrives at the bound is reported with the property that produced it - no driver knows why it was cancelled - carrying over the SQL state and the error number, and without the statement itself, which a driver renders with its parameters bound. JDBCStatementBoundTestCase covers the policy and both classification branches without a database; the container suites block a write and a bulk statement behind an uncommitted transaction of another session and require each to give up inside the bound of its own class.
…bound, never loosen one The socket read timeout armed behind the cancel of a statement was set unconditionally, so a connection already carrying a read timeout of its own had it replaced for the duration of every statement - by a looser value, by construction, since the backstop is deliberately the cancel's bound plus a margin. A deployment that bounds the reads of its connections (the setting OpenIdentityPlatform#885 asks for) would have found that bound ignored exactly while a statement was running, which is when it matters. It is armed now only when there is something to gain: when the connection carries no bound at all, which is "no timeout" in the JDBC contract, or when the one it carries is looser than the backstop. Where nothing is changed, nothing is put back afterwards either.
…scan of a backend open its own class The review of OpenIdentityPlatform#882 found the bound covering less than its javadoc claims. The rows were read after it was released. bounded() put the socket read timeout back in a finally that runs before the caller has seen a single row, and the transfer is where the wait lives: a driver hands rows over as they are asked for, and setQueryTimeout covering ResultSet.next() is optional in the JDBC contract. PostgreSQL and MySQL buffer a result whole and were never affected, but oracle prefetches ten rows against batches of a thousand and mssql buffers adaptively, so on both of them nearly every round trip of a batch ran with neither layer armed - and on mssql, where a select under READ COMMITTED really does block on a row another session holds, that is the symptom of OpenIdentityPlatform#877 itself. executeResultSet() hands the rows to its caller now instead of returning a live ResultSet, so the transfer, the classification of a failure and the release of the backstop all happen where the statement does. positionToLastKey() was bounded as an operation. It has no key to seek on, so it is an "order by k desc" over the whole table - a scan and a sort of it on mssql, where k is a varbinary(max) that cannot be an index key - and every open of a backend runs it once per base DN, through EntryContainer.getHighestEntryID(), outside the try/catch of BackendImpl.openBackend(). Two minutes there turns a large backend that opens slowly into one that does not open at all. It takes the bulk class now, which fetchBatch() receives from its caller rather than deriving from the shape of the query: the first batch of every cursor carries no condition either, and that one is on a search path and stays an operation, as does the VLV offset of positionToIndex() - a client-driven offset is exactly what has to give the worker thread back. Also from the review: - the catalog lookups of openTree(), getTables() and getIndexInfo(), went through no bound at all. DatabaseMetaData takes no query timeout, so they get the socket read timeout alone, as the operations they are: they run once per tree on every open, behind the same locks as the create table they guard; - setQueryTimeout() was called outside any try. The contract allows SQLFeatureNotSupportedException and this backend takes whatever URL a deployment configures, so such a driver now degrades to the backstop with one warning instead of failing every statement it is given; - the bound was measured on the wall clock, which a step of it could lengthen or shorten. It is the monotonic clock now; - the warning about a driver that will not take a backstop was static: the first backend to hit it silenced it for every other one in the JVM. It is per storage, and the same is true of the new one above it; - ImporterImpl.close() ran "con.commit(); con.close();" with nothing between them, so a commit that throws left the connection out of the pool for good, holding the transaction and the locks of that import - and the bulk bound makes that reachable, since a clearTree() that gives up closes the importer on its way out. The connection goes back whatever the commit does, and the storage this importer opened is closed whatever the connection does; - seconds() said a value that is not a number leaves a class unbounded. Integer.getInteger() falls back to its default instead, which is what the test asserted all along; the javadoc, the test name and the description of the bulk class shipping unbounded say so now. JDBCStatementBoundTestCase covers the rows being read while the bound is still armed and a failure during that transfer being measured against it, a driver without a query timeout still running under the backstop, a catalog lookup being bounded, and the class of both kinds of cursor batch - 15 tests, no database, 3 s. PgSql 39/39, MySql 39/39, MsSql 39/39, Oracle 39/39 and the JDBC EncryptedTestCase 34/34 pass with no skips.
1485984 to
b7c7421
Compare
|
Rebased onto master (0b9c0f6), which had moved on under the JDBC backend since this branch was cut (#886 catalog lookup, #866 table stamping and statistics, #867 SQL Server upsert). Conflicts and how they were resolved:
One thing beyond the conflict markers: this PR replaces
|
maximthomas
left a comment
There was a problem hiding this comment.
Reviewed at b7c74213279a3816ef1337858e7563265450104e against master 0b9c0f63f5. The rebase itself is clean — I checked the four seams you listed and found no loss: isExistsTable() propagates a timeout instead of returning false (no spurious create table), the lifted final byte[] value keeps hashParam(con), all four #867 hashParam sites survive, and timedOut() copies SQLState and vendor code so #867's retry classifier still sees a class-40 conflict as retryable and a cancel (57014 / ORA-01013 / HY008 / 70100) as not. One blocker, two majors, one minor below.
The backstop is connection-wide, but the importer shares one connection across all import threads (blocker)
opendj-server-legacy/src/main/java/org/opends/server/backends/jdbc/JDBCStorage.java:246-252, :310-312, :222-224
armBackstop() sets Connection.setNetworkTimeout() — a property of the socket, not of the statement. ImporterImpl holds exactly one Connection (:1729, assigned :1758) and gives it to both transactions:
txr = new ReadableTransactionImpl(con);
txw = new WriteableTransactionTransactionImpl(con);OnDiskMergeImporter drives that single Importer from nbThreads phase-one workers (OnDiskMergeImporter.java:903/:921/:943) and one phase-two task per tree (:1286 invokeParallel). Two consequences:
(a) ImporterImpl.clearTree (:1803-1805 → txw.clearTree :1387, BULK) short-circuits at :222-224 and arms nothing, but runs on a socket a concurrent OPERATION set to 150 000 ms. Pooled connections start at networkTimeout 0 (the dialect connect properties go only to newStampConnection, :582-585), so the arm always takes effect. A multi-minute delete from <table> dies at 150 s, the driver closes the connection, and import-ldif fails where it previously completed slowly — and since BULK never entered bounded(), timedOut() never runs, so the error names nothing.
(b) With N concurrent statements only the first arms; the rest hit
if (previous > 0 && previous <= backstop) {
return -1;
}and arm nothing, then the first restores 0 at :252 while they are still in flight. During any import most statements run with the socket layer off — the layer the javadoc at :215-218 says exists because Oracle "does not process the break its driver sends".
Cheapest fix: skip the backstop on the importer's connection; it is the only shared one, every other is borrowed per read()/write(). Thorough fix: move arm/release into CachedConnection behind a lock with an outstanding-statement count, arm to the tightest value requested, restore only at zero, and let BULK register "no bound" instead of short-circuiting before armBackstop.
The cursor batch bound aborts rebuild-index on SQL Server (major)
opendj-server-legacy/src/main/java/org/opends/server/backends/jdbc/JDBCStorage.java:1582
The first batch of a cursor has no seek predicate, so fetchBatch (:1549-1560) issues an unconditioned order by k over the whole table, and next() gives it OPERATION (120 s):
if (buffer.isEmpty() && !fetchBatch(currentKeyDb==null?null:">", currentKeyDb, 0, false,
adaptiveBatchSize(), StatementBound.OPERATION)) {On mssql k is not indexable — your own comment at :1364 says so, and the create index (k) at :1332-1360 covers postgres/mysql/oracle only:
// mssql: k is varbinary(max), which cannot be an index key column - cursor batches stay unindexed thereso SQL Server scans and TOP-N sorts the whole table. rebuild-index reaches this path: OnDiskMergeImporter.java:1086 importer.openCursor(id2Entry.getName()) in ID2EntrySource.processAllEntries, constructed at :551 under rebuildIndex(...), entered from BackendImpl.java:786. Past 120 s the driver cancels, fetchBatch throws, and the rebuild aborts — master ran the same scan unbounded (master's fetchBatch took no bound and used the untimed executeResultSet(statement)). No client is waiting, so the OPERATION rationale does not apply here.
Fix: take next()'s class from the caller the way fetchBatch already does elsewhere — importer/rebuild cursors are BULK, client-search cursors stay OPERATION. Same pattern you already applied to positionToLastKey (:1694).
The statistics refresh gets the query timeout but not the backstop (major)
opendj-server-legacy/src/main/java/org/opends/server/backends/jdbc/JDBCStorage.java:959, :977
statement.setQueryTimeout(timeoutSeconds); // 0: wait without limit
...
executeAny(statement);executeAny() (:354-359) just calls statement.execute() — no bounded(), so armBackstop never runs, and the connection is a pooled one with networkTimeout 0. This is the only statement in the file with layer 1 and not layer 2. It runs on Oracle, as dbms_stats.gather_table_stats, inside ImporterImpl.close() — after the data is committed. By the premise of your own javadoc at :215-218, if the cancel is not acted upon the 600 s bound never arrives and import-ldif parks forever at the end of a successful import, holding the pooled connection, with no error.
Not a regression (master had neither layer here), but the PR title says every statement is bound and this is the counterexample, on the named engine. The tool already exists: the bounded(Connection, StatementBound, Execution) overload isExistsTable uses arms only the socket backstop, so wrapping these statements in it keeps the 600 s bound and closes the gap.
The container bound test cannot fail for the reason it exists (minor)
opendj-server-legacy/src/test/java/org/opends/server/backends/jdbc/TestCase.java:254, :282-286
final int boundSeconds = 5;
...
} catch (Exception expected) {
// the bound was reached and the transaction rolled back
}
final long elapsed = System.currentTimeMillis() - startedAt;
assertTrue(elapsed < 120000, "gave up only after " + elapsed + " ms");The bound is 5 s and the asserted ceiling is 120 s. On MySQL the blocked statement runs on a pooled connection and lockTimeoutSql reaches only stamp connections (:582, :588), so InnoDB's own 50 s innodb_lock_wait_timeout ends the wait inside the ceiling — both testWriteBlockedByAnotherSessionGivesUpAtItsBound and testBulkStatementGivesUpAtItsOwnBound pass with bounded() deleted. And any exception satisfies the catch, so a run failing instantly for an unrelated reason passes at t≈0 too.
Assert against the bound (elapsed >= boundSeconds * 1000 and elapsed < boundSeconds * 4 * 1000) and assert the exception is the one the bound produces — SQLTimeoutException, or that the message names the property, which timedOut() puts there. Setting the untested classes to "0" and clearing every property in the finally is right and worth keeping.
Nits
- Vacuous BULK assertion:
JDBCStatementBoundTestCase.java:117-118sets BULK's property to a non-number and assertsBULK.seconds() == 0, but BULK's default is already0— it passes whether the fallback works, the value parses as 0, or the property is never read. Set a numeric value first, then a non-numeric one. Only the OPERATION half at:114-115currently pins the fallback. - Javadoc claims coverage the suite does not have:
JDBCStatementBoundTestCase.java:143-144says the backstop is put back "so a bulk statement sharing the connection is not cut by the bound of an entry read", but the test drives one mock connection from one thread in sequence. That is exactly the property the blocker above shows the code lacks. (The rest of the suite is load-bearing: removing the tighten-only guard fails:167-177, dropping the release fails theinOrderat:158/:248, misassigningpositionToLastKey/nextfails:325-340.) - Comment on the wrong method: the "The connection goes back whatever the commit does…" block landed above
aborted(), which only sets a flag. It describesclose(), which is where the nestedfinallyit explains actually is.
…ion between the statements on it The backstop behind the cancel is a property of the socket, and it was armed and put back per statement. On the one connection this backend shares - the importer holds a single one for the whole of an import and writes to it from every phase-one worker and every phase-two task - that meant the first statement to finish took the backstop away from those still in flight, while a statement of a class carrying no bound ran under whatever a concurrent one had armed, dying at a bound it was never given and naming no property for it. The value armed is now the loosest of the bounds in flight, a statement with no bound of its own takes it off for as long as it runs, and what the connection carried before is put back when the last of them is through. The batches of a cursor take the class of whoever opened it: an import or a rebuild-index walks a whole tree with no client waiting, and on mssql walks it unindexed, so bounding those as entry reads aborted a rebuild that ran to the end before. Client cursors stay operations. The statistics refresh had the cancel but not the backstop, on oracle - the engine that does not act on a break - at the very end of a successful import. It now runs under both, under the bound of its own property rather than of a class, which would have put 120s over a statement allowed 600. The container bound test asserted a 120s ceiling on a 5s bound and accepted any exception, so it passed with the bound deleted; it now asserts the window of the bound and that the failure names the property that produced it.
|
Thank you — the blocker and both majors were real, and every line reference checked out again. All of it is addressed in The backstop is connection-wide, but the importer shares one connectionConfirmed, and taken the thorough way rather than by skipping the importer's connection: the socket read timeout is now arbitrated between the statements running on one connection instead of being armed and put back per statement. A
The state is keyed by identity on the connection of the driver, since Your trace of where the overlap comes from holds, and it is narrower than "phase one runs on N threads": One corollary the review did not name, which the shared release also fixes: The cursor batch bound aborts
|
maximthomas
left a comment
There was a problem hiding this comment.
Reviewed at c1508e0fc68cc24f64c31f9d804931cc1eda045f against 0b9c0f63f5.
The Backstop redesign is right. I tried hard to break it and could not: the "a failed restore leaves
a stale networkTimeout on a pooled connection" theory is unreachable, because on all three
non-postgres drivers every throwing path in setNetworkTimeout implies the connection is already
closed, and a dead one fails isValid(0) on borrow. The "the restore strips the stamp connection's
connect-property read timeout" theory is also false — all four drivers do report that value from
getNetworkTimeout() (ojdbc via T4CConnection's override, not PhysicalConnection), so
previous is 30000, the tighten-only guard returns, and nothing is armed there at all. Fixes (3),
(4), (5) and (6) check out.
Fix (2) does not. It went in one level too low, and it is the one that makes a server fail to start.
The bulk cursor class was added below the SPI, so only the importer can reach it (blocker)
openBulkCursor() is package-private on ReadableTransactionImpl and is not on the SPI, which
declares only openCursor:
// opendj-server-legacy/src/main/java/org/opends/server/backends/jdbc/JDBCStorage.java:1376
public Cursor<ByteString, ByteString> openCursor(TreeName treeName) {
return new CursorImpl(isReadOnly, con, treeName, StatementBound.OPERATION);
}
...
// :1387 — not on org.opends.server.backends.pluggable.spi.ReadableTransaction
Cursor<ByteString, ByteString> openBulkCursor(TreeName treeName) {
return new CursorImpl(isReadOnly, con, treeName, StatementBound.BULK);
}Its only caller is ImporterImpl.openCursor() (:1970). Every other holder of a
ReadableTransaction lands on :1376 and keeps 120 s per batch — and on SQL Server every batch is a
full scan and sort, as the file's own comment at :1500 says, because k is a varbinary(max) and
create index (k) covers only postgres/mysql/oracle (:1470/:1479/:1491).
That is still rebuild-index's problem, plus export-ldif, verify-index and dbtest. But the path
that matters is not a command line:
LDAPReplicationDomain.computeGenerationId() :3191-3193
-> exportBackend(null, true) -> backend.exportLDIF(exportConfig)
-> BackendImpl.java:624 new ExportJob
-> ExportJob.java:175 txn.openCursor(id2entry.getName()) // OPERATION, 120 s per batch
computeGenerationId() is called at LDAPReplicationDomain.java:3326, on the if (!found) branch of
loadGenerationId() — the first start of a replicated domain, with no operator involved (also at
:3605 after a failed import, and via initializeRemote for a total update). Master had no bound on
any cursor, so this server started before the PR. Now, on a large enough SQL Server backend, the
generation ID is never computed and the domain does not come up.
Putting the choice on the SPI fixes all of these at once; covering only
ExportJob/VerifyJob/BackendStat would leave the four cursor call sites in DN2URI, VLVIndex,
PersistentCompressedSchema and ID2Entry unclassified — I did not trace those to their callers.
The importer's own writes and reads keep the 120 s bound, and the new comment says they do not (major)
// opendj-server-legacy/src/main/java/org/opends/server/backends/jdbc/JDBCStorage.java:1965
// Bulk, like everything else an import does: this walks a whole tree with no client waitingOnly clearTree (:1521) and deleteTree (:1533) are BULK. ImporterImpl.put (:1955) reaches
upsert, whose every dialect branch calls the one-argument overload:
// :191
int execute(PreparedStatement statement) throws SQLException {
return execute(statement, StatementBound.OPERATION);
}and ImporterImpl.read (:1960) reaches the two-argument executeResultSet at :1369, also
OPERATION. Master issued both raw, with no setNetworkTimeout anywhere and no socketTimeout on
pooled connections, so every row an import writes gains a 120 s ceiling it did not have.
Reachability is narrower than the cursor case and I want to be accurate about it: this needs a
concurrent writer, not merely a large import. The importer's own threads share one Connection
(:1907), so they are one session and cannot lock-block each other. But h is the primary key on
every dialect and the default lock wait is forever on mssql, postgres and oracle, so an upsert blocked
by an LDAP write on the same table during an online ImportTask or rebuild-index does sit until
120 s and then fails the import. MySQL escapes only because its own 50 s innodb_lock_wait_timeout
fires first.
Either give put/read BULK — which is what the comment already claims — or leave them OPERATION
deliberately and correct the comment, which is currently false about the code directly beneath it.
The new concurrency tests pin re-entrancy, not concurrency (minor)
Two of the three issue their second statement from inside a Mockito Answer, on the same thread:
// opendj-server-legacy/src/test/java/org/opends/server/backends/jdbc/JDBCStatementBoundTestCase.java:205
when(operation.executeUpdate()).thenAnswer(new Answer<Integer>() {
public Integer answer(InvocationOnMock invocation) throws Throwable {
storage.execute(bulk, StatementBound.BULK); // what another thread of the import is doing
return 1;
}
});Backstop's synchronized blocks are reentrant, so this takes both monitors trivially — a lost update
on bounds/unbounded/holders under real threads would still pass. The one genuinely two-threaded
test (:227) gives both statements OPERATION "7", so two distinct bounds are never merged or
decremented concurrently.
testTheBackstopFollowsTheLoosestBoundInFlight (:281) also arms the loose bound first and lets the
tight one join, so wanted never changes and applyBackstop's re-arm branch is never entered with
armed > 0 && wanted > 0. Nothing tests the reverse order (OPERATION in flight, BULK joins, must
re-arm 37000 -> 130000) or the tighten-back-down when the looser statement finishes first.
And testTheBatchesOfAnImportCursorAreBulk (:478) passes BULK to CursorImpl by hand;
openBulkCursor appears nowhere in either test file, so reverting ImporterImpl.openCursor to
txr.openCursor() — the blocker above — passes the whole suite.
The cross-thread test hangs the build instead of failing it (minor)
JDBCStatementBoundTestCase:227 has three untimed waits — mayFinish.await() (:239),
running.await() (:259), concurrent.join() (:268) — and no timeOut on the method or the class,
unlike TestCase.java:208/:229. running.countDown() is inside the mock's Answer (:238), so if
storage.execute(lingering) throws before reaching it, the main thread parks at :259 forever.
The background throwable is also dropped:
// :243
public void run() {
try { storage.execute(lingering); }
catch (SQLException e) { throw new RuntimeException(e); } // nothing captures this
}join() does not rethrow, and releaseBackstop runs in a finally, so a failure after the
countdown still leaves the InOrder verification passing.
The container test times with the wall clock (minor)
// opendj-server-legacy/src/test/java/org/opends/server/backends/jdbc/TestCase.java:293
final long startedAt = System.currentTimeMillis();
...
assertTrue(elapsed >= boundSeconds * 1000L, ...); // :316, no slacktimedOut()'s own comment says the production measurement is taken from the monotonic clock "which a
step of the wall clock can neither lengthen nor shorten"; the test that checks it uses the wall clock,
with zero slack on the floor.
Round 4's finding is otherwise genuinely fixed — namesTheBound (:306) works, because timedOut()
only puts the property in the message once the bound has elapsed, so an instant unrelated failure can
no longer pass. What it does not exclude is a post-bound unrelated failure, since timedOut()
relabels any SQLException arriving after seconds as that property's breach.
Nits
unsupporteddoes not survive, so its comment is wrong: the comment atJDBCStorage.java:437
says a driver with no network timeout "is not asked again", butunsupportedis a field of
Backstop, andreleaseBackstopdrops the entry whenever--holders <= 0(:388). With one
statement at a time the latch dies at every release, so such a driver is asked, throws and is caught
once per statement forever.- The one-shot warning is spent by the wrong cause:
backstopWarned(:294) is CAS'd at:440
inside the single catch its own comment says serves both causes. The common one — a connection on
its way out — permanently consumes the one shot and silences the genuine "this driver has no network
timeout" warning for the life of the storage. - "Only the comment DDL is left outside both layers" is not exhaustive:
executeSessionStatement— theset lock_timeout/alter session set ddl_lock_timeoutissued from
newStampConnection— is outside both layers too. Harmless for the same reason (it runs on a stamp
connection), but worth naming under "Out of scope". timedOut()names a property theConnectionoverload never set:bounded(Connection, StatementBound, Execution)sets no query timeout, yet a failure aftersecondsis rewritten to
"did not finish within the 120s of ...jdbc.query.timeout: raise that property". On a pooled
connection the only layer in force there is the backstop at bound+30 s, so a catalog lookup that
fails at 121 s from a reset connection points the operator at the wrong knob.positionToKey()anddelete()never gotbatchBound(:1812,:1767) and stay OPERATION on
a bulk cursor. Unreachable today —ImporterImpl.openCursordeclaresSequentialCursor, and
delete()throws on the read-only transaction — so this is consistency only.
…it belongs to, not to the call site that reaches it The bulk class of a cursor's batches went in below the SPI: openBulkCursor() was package-private on the JDBC transaction, so only the importer could reach it and every other holder of a ReadableTransaction kept the bound of an entry read over a walk of a whole tree. On mssql such a walk is a scan and a sort of the table for every batch - k is a varbinary(max) there, which cannot be an index key - so an export, a verify and dbtest failed at two minutes on a backend large enough, and so did two paths with nobody at a command line: the read that checks id2entry is there on every open of a backend (ID2Entry.afterOpen, through EntryContainer.open, outside the try/catch of BackendImpl.openBackend), and the generation ID a replicated domain computes for itself the first time it starts (LDAPReplicationDomain.loadGenerationId -> computeGenerationId -> exportLDIF). The choice is on the SPI now, as a default method answering exactly as openCursor(), so every engine that bounds nothing inherits it unchanged and the walks no client waits on ask for it. An import takes the bulk class for every statement it issues, not only for the two that empty a tree: the class belongs to the transaction, so put(), read() and the batches of the importer's cursor take it as well. Only the catalog lookups of openTree() keep the operation class whoever runs them - they read a data dictionary rather than the data, so a wait there is another session's metadata lock, which is one of the waits this bound exists to end. A statement bounded by the socket read timeout alone - a DatabaseMetaData lookup takes no query timeout, and a driver is free to refuse one - is measured against what that layer really allows it, its bound plus the margin, rather than against a property that bounded nothing: a connection reset at 121 s was reported as a query timeout of 120 s and sent the operator to the wrong knob. A driver with no network timeout at all is told apart from a connection that failed the call: the first is remembered for the storage, which is the scope of a driver, the second only while the statements on that connection run, and each has a warning of its own instead of the common cause spending the single shot the real one needs. positionToKey() and delete() take the class of their cursor, and the session statement of a stamp connection is named as being outside both layers. The tests that drove two statements from one thread drive them from two, the one that could hang the build bounds every wait and rethrows what the background thread threw, the order that re-arms the backstop upwards and tightens it back is covered, the wiring of an import is pinned through a real ImporterImpl, the bulk cursor of the open path through ID2Entry, and the container test measures with the monotonic clock, as the code it checks does.
|
Thank you — the blocker, the major and every minor were real, and each line reference checked out again. All of it is addressed in The bulk cursor class was added below the SPIConfirmed and fixed the way you proposed: I traced the four call sites you left open, and two of them turned out to matter:
Your generation-ID path is exactly as you traced it — The importer's own writes and reads keep the 120 s boundConfirmed, and taken the first of the two ways you offered: the comment is now true of the code. The class is a property of the transaction rather than of a call site, so The catalog lookups of The tests
Nits
Verification
|
maximthomas
left a comment
There was a problem hiding this comment.
Verdict: ship with fixes — two of them before merge. Nothing here is a regression against master
and there is no defect in the production change. What is missing is the test that keeps round 5's
blocker fixed (blocking) and a test ceiling that scores a working backstop as a failure (blocking).
Everything else is follow-up material.
praise: round 5's blocker is genuinely fixed.
openBulkCursor is on the SPI as a default, and all four paths the last round named reach it —
export-ldif and the replication generation-ID walk via ExportJob:179, verify-index via VerifyJob
(×5), dbtest via BackendStat (×2), import/rebuild via ImporterImpl. The one in-repo decorator,
TracedStorage, overrides both wrappers (:303/:390). The importer's put/read took the first
of the two options offered, and the javadoc now matches: ImporterImpl exposes only
aborted/close/clearTree/put/read/openCursor, no openTree.
issue (blocking): the fix is pinned at 1 call site out of 12.
opendj-server-legacy/src/main/java/org/opends/server/backends/pluggable/ExportJob.java:179
Pinned: ID2Entry.java:389 (via ID2EntryTest:48/52) and the JDBCStorage override itself
(JDBCStatementBoundTestCase:586). Unpinned: ExportJob:179, VerifyJob:349/446/529/611/659,
BackendStat:1121/1290, PersistentCompressedSchema:151/174, DefaultIndex:142,
ID2ChildrenCount:69, ShardedCounter:84, TracedStorage:303/390.
Reverting any of the eleven is invisible twice over — off JDBC because
spi/ReadableTransaction.java:62 is a default that calls openCursor, and on JDBC because no test
in src/test/.../backends/jdbc/ (9 files) reaches the pluggable layer at all. A later refactor of
ExportJob, or a merge conflict resolved in it, silently restores the 120 s bound on the generation-ID
walk — round 5's blocker — with CI green.
This is round 5's finding [3] recurring on the fix for round 5's finding [1].
Marked blocking despite the code at HEAD being correct, and the reason is the recurrence rather than the
severity: the same revert-and-still-pass gap was raised last round, fixed for one call site, and is back
at 2-of-12. Deferring it to a follow-up is the same bet that already lost once, and what it protects is
blocker-severity behaviour.
Two Mockito assertions in the shape
ID2EntryTestalready uses — one onExportJob, one on a
VerifyJobpath — make a revert visible. Two of eleven is enough.
issue (blocking): the container-test ceiling is below the backstop it arms, on 3 of 4 engines.
opendj-server-legacy/src/test/java/org/opends/server/backends/jdbc/TestCase.java:319-320
final long ceilingSeconds = getJdbcUrl().startsWith("jdbc:oracle")
? boundSeconds + JDBCStorage.BACKSTOP_MARGIN_SECONDS + 10 : boundSeconds * 4L;boundSeconds = 5, so the non-oracle ceiling is 20 s. But BACKSTOP_MARGIN_SECONDS = 30 and
backstopMillis() arms the socket layer at (5+30)*1000 = 35 s — and holdBackstop() is not
dialect-gated, so 35 s is armed on all four engines.
On pg/mysql/mssql, a run where the driver's cancel does not land ends at ~35 s. namesTheBound passes,
then the ceiling assertion fails with "gave up only after 35xxx ms, past the 20 s this bound of 5 s
allows". The second layer doing its job is scored as the bound failing. The test contradicts its own
subject.
Blocking because it is a test that fails when the code works: the next red on those suites reads as a
product bug. One line, test-side only.
Give the other three the oracle branch's shape (
bound + margin + 10= 45 s). Still under MySQL's
50 sinnodb_lock_wait_timeout, which is what the ceiling exists to catch.
I could not measure how often this fires — it depends on whether pgjdbc's and Connector/J's out-of-band
cancel can fail to land under this fixture, which I did not check.
issue (non-blocking): CLOCK_SLACK_MILLIS is unreachable — the round-5 fix rescues nothing.
opendj-server-legacy/src/test/java/org/opends/server/backends/jdbc/TestCase.java:311 runs before
the new slack at :322:
assertTrue(namesTheBound(failure, bound), ...); // :311 — runs first
...
assertTrue(elapsed >= boundSeconds * 1000L - CLOCK_SLACK_MILLIS, ...); // :322 — the new slackand opendj-server-legacy/src/main/java/org/opends/server/backends/jdbc/JDBCStorage.java:494 has no
slack of its own:
if (System.nanoTime()-startedAt < endsAfter*1_000_000_000L) {
return e; // raw driver exception, unlabelled
}A driver reporting the cancel at bound*1000 - 5 ms gets the raw exception. namesTheBound looks for
bound.property, a string only timedOut()'s wrapper emits, so :311 fails with "does not name".
The window [bound*1000-250, bound*1000) is exactly what :311 rejects.
Widened further: the test's startedAt (:298) precedes prepareStatement, while timedOut()'s
starts inside bounded() — the test can measure over the bound while timedOut() measures under it.
Put the slack in
timedOut()at:494, not only in the test. Otherwise the production message is
missing for exactly the case this fix identified.
note: after this fix, three server-driven paths wait forever — so "bound every statement" no longer
describes the PR. Deviation, not a defect; your call.
ID2Entry.java:389, PersistentCompressedSchema.java:151/:174, ExportJob.java:179.
BULK is 0 at both layers, and applyBackstop with wanted==0 && armed==0 returns without touching the
driver. Reachable unattended:
start-ds→BackendImpl.openBackend:196→RootContainer.open:130→PersistentCompressedSchema
ctor:94(two whole-tree walks) andAbstractTree.open:43→ID2Entry.afterOpen:389LDAPReplicationDomain.loadGenerationId:3326→computeGenerationId:3191→ExportJob:179, on
first start of a replicated domain
On a blocked table, start-ds parks with no message and no timeout.
This is a return to master, not a regression — at base, fetchBatch used the untimed
executeResultSet and the pool carries no read timeout (the socketTimeout properties are the #866
stamp connection's). The 120 s these paths carried at the previous head was the new behaviour, and it
was the blocker. So the trade is right for this PR.
Either narrow the claim in #877, or open a follow-up for a separate, wider startup bound.
suggestion (non-blocking): the import test pins layer 1 but never enters layer 2.
opendj-server-legacy/src/test/java/org/opends/server/backends/jdbc/JDBCStatementBoundTestCase.java:602
It is a real pin, not a vacuous one — put() reaches execute(.., BULK) twice through the ANSI
branch, read() and the cursor reach executeResultSet(.., BULK), and flipping any one to OPERATION
fires setQueryTimeout(7) so never() fails. But:
final Connection parent = mock(Connection.class);
when(parent.prepareStatement(anyString())).thenReturn(statement);
// statement.getConnection() is NOT stubbed here (cf. lingering() at :107)connectionOf (:282) returns null → holdBackstop (:362-364) returns null. So the test pins
"an import sets no query timeout" but not "an import takes the backstop off" — the half that decides
whether an import can hang on a dead TCP peer.
Separately: the mock's class name matches no dialect, so the ANSI else (:1652) is the only upsert
branch any test executes. :1625/:1632/:1639/:1646 are covered by nothing. Pre-existing gap,
noted not blocking.
nitpick (non-blocking): timedOut() understates the elapsed time by the margin, in the case you
document yourself.
opendj-server-legacy/src/main/java/org/opends/server/backends/jdbc/JDBCStorage.java:493
final long endsAfter = cancelArmed ? seconds : seconds+(long)BACKSTOP_MARGIN_SECONDS;On Oracle setQueryTimeout succeeds, so cancelArmed is true — but the session ignores the break and
the wait ends at the socket layer 150 s later. Your own test comment says so:
"Oracle is given the second layer as well — a session blocked in a row-lock enqueue does not act on
the break its driver sends, so the wait there ends at the socket read timeout."
The message then reports "did not finish within the 120s" for a statement that waited 150 s.
cancelArmed cannot tell "armed" from "armed and obeyed".
Not a misdirection — backstopMillis() derives the socket layer from the same seconds, so the property
named governs both layers and raising it is the right remedy. Message accuracy only.
Report the observed elapsed, or word it "at least".
nitpick (non-blocking): the class-level timeOut is inert, and the comment above it is false.
opendj-server-legacy/src/test/java/org/opends/server/backends/jdbc/JDBCStatementBoundTestCase.java:67
// timeOut on the class, not on the waits inside a test: a statement of another thread that never
// arrives has to fail this suite rather than hang the build waiting for it.
@Test(groups = { "precommit", "jdbc" }, sequential = true, timeOut = 120000)Every method carries a bare @Test. Measured on testng-6.14.3 (javap -c TestNGMethod.init): the
class lookup runs only when the method annotation is absent, so a bare method @Test wholly replaces
the class one and timeOut resolves to 0. groups survives only because initGroups(Class) merges
separately.
It does not matter — awaitOrFail (30 s) and joinOrFail (join(30 s) + assertFalse(isAlive)) bound
every wait, so round 5's [4] is fixed, just not by the declared mechanism. The comment now describes
neither TestNG's behaviour nor the code beneath it.
Drop the attribute and the comment; the bounded waits are the real protection.
chore (non-blocking): leftovers from the conversion.
ID2ChildrenCount.java:60—openCursor(ReadableTransaction)is dead;VerifyJob:529was its only
caller and now usesopenBulkCursor. It keepsShardedCounter.java:76alive as dead code too (sole
caller isID2ChildrenCount:62). Delete both.Index.java:50—openBulkCursoris abstract with nodefault, the one interface in the change set
not using the compatibility pattern the SPI change relies on. Harmless today (package-private,
DefaultIndexthe only implementor); a future implementor gets a compile error, not a fallback.JDBCStorage.java:1453—getRecordCounthardcodes BULK and ignores the transaction's newbound
field, the only place the class is overridden downward:All callers today are admin/import; the hazard is the next one, since it is reachable through thereturn executeResultSet(statement, StatementBound.BULK, rc -> rc.next() ? rc.getLong(1) : 0);
publicTree.getRecordCount(ReadableTransaction).BackendStat.java:1121carries no comment while its twin at:1290does.
… measure the bound as the clock does The bulk cursor was on the SPI but held by two tests out of twelve call sites, so a revert of any of the other ten compiled, ran and stayed invisible - on JDBC it would put the 120 s of a client operation back on the export behind a replicated domain's generation ID. BulkCursorTest pins ten of them, and the deletion of the dead ID2ChildrenCount.openCursor makes the eleventh a compile error. The container bound test asserted a ceiling of four times the bound while the socket read timeout behind it is armed at the bound plus its margin on every engine, so the second layer ending a wait the driver's cancel did not was scored as the bound failing. The ceiling is now that layer, and the blocking session is rolled back whatever the assertions do, so a failed one cannot leave the drop that follows waiting on its lock. timedOut() gains the slack the test had - a driver keeps its timer in whole seconds, and measured to the millisecond the one failure this classification exists to name arrived unlabelled - and reports the time the statement really took rather than the bound it reached, which on oracle is a margin later. positionToKey() reads a row whose v is null as the failure it is rather than as a missing key, and startImport() returns the connection it borrowed when the importer cannot be built on it.
|
Thanks — both blockers are fixed in The fix is pinned at 1 call site out of 12 (blocking)Fixed, at 10 of 12 by test and one more by the compiler. New
Two are left uncovered and named in the suite's javadoc rather than passed over: the attribute index of Two corrections to the reasoning, neither of which changes your conclusion:
The container-test ceiling is below the backstop it arms (blocking)Fixed. The ceiling is now
|
maximthomas
left a comment
There was a problem hiding this comment.
praise: Every item from the last round landed as described, and three of them landed better than asked.
- The counter-class fix is threaded correctly at every hop —
ID2ChildrenCount:167→ShardedCounter:145→openCursor0:94, both 2-arg overloads delegatingfalse,removeCounthard-pinned, andVerifyJob:525the onlytruein the repo. BACKSTOP_ALONEas a constant shared between the production message and the assertion is the right shape: a reworded message moves both halves together instead of quietly un-pinning the test.- The one-record
BulkCursorTestfixture is genuinely load-bearing, not decoration —VerifyJob:492-499pushes counters inside the cursor loop and only the post-loop drain reachesgetCount(txn, parent.entryID, true), so an empty tree would have yielded zeroopenBulkCursorcalls and the pin would have passed on nothing. - Reverting each fix to confirm exactly the expected test goes red is the discipline that makes the rest of this reviewable.
- Saying outright that
testStartImportGivesTheConnectionBackWhenTheImporterCannotBeBuiltwould not have gone red against thecatch (RuntimeException)it replaces, rather than claiming coverage it doesn't have. - The import connection is uniformly
BULKby construction —ImporterImpl:2110-2112builds both transactions that way, andclearTree/getRecordCounthard-code it. That uniformity is what makes a whole class of shared-connection timeout races unreachable, even at ~25 concurrent holders through oneImporterImpl.con. Worth keeping deliberate.
issue (blocking): VerifyJob:1041 is the one branch of its if/else left at the operation class.
opendj-server-legacy/src/main/java/org/opends/server/backends/pluggable/VerifyJob.java:1041
The if (indexIterator) arm has four branches, all pinned BULK through getRecordCount (JDBCStorage:1588-1590). The else arm is not:
else if (!vlvIndexList.isEmpty()) {
totalCount = vlvIndexList.get(0).getRecordCount(txn); // BULK
}
} else {
totalCount = rootContainer.getEntryContainer(verifyConfig.getBaseDN())
.getNumberOfEntriesInBaseDN0(txn); // -> getTotalCount -> getCount(txn,key) -> false
}txn comes from verifyBackend():133 storage.read(...) — ReadableTransactionImpl(con), pinned OPERATION at JDBCStorage:1534-1536 — and ProgressTask is built at :247 outside the inner try.
On MS SQL Server k is varbinary(max) and cannot be an index key: getTableDialect:1650 declares primary key(h) only, and :1700 gives postgres/mysql/oracle a create index on <t>(k) and mssql none. So the first batch is a scan and a sort of the whole table under ~120 s:
select k,v from opendj_<hash> where k>=? order by k offset ? rows fetch next 32 rows onlyBlocking because this is a regression, not a gap left open. Base 0b9c0f63f5 has one setQueryTimeout in the entire backend (:743, the statistics refresh) and no query.timeout property, so this read is unbounded today and a large-backend verify completes. After the merge it aborts before its first record — the job #877 exists to protect.
Fix is the machinery already built:
// VerifyJob:1041
totalCount = rootContainer.getEntryContainer(verifyConfig.getBaseDN())
.getNumberOfEntriesInBaseDN0(txn, /* partOfAWholeTreeWalk */ true);
// -> getTotalCount(txn, true) -> getCount(txn, key, true)Keep the 2-arg form for the client callers — LocalBackendMonitor:95/:109 (cn=monitor), GroupManager:532, SubentryManager:275, AciListenerManager:348 all reach the same read with a client waiting, where OPERATION is correct. A BulkCursorTest pin on the else arm would match the four siblings that already have one.
question (blocking): What is the upgrade story for the 120 s default?
opendj-server-legacy/src/main/java/org/opends/server/backends/jdbc/JDBCStorage.java:130
Base bounds nothing; OPERATION ships 120. So every client statement in an existing JDBC deployment goes from unbounded to 120 s on upgrade, and the only lever is:
OPERATION("org.openidentityplatform.opendj.jdbc.query.timeout", 120)
// seconds() -> clampSeconds(Integer.getInteger(property, defaultSeconds))Integer.getInteger only — no dsconfig, no cn=config, and no admin-guide change in this PR. Any deployment with operations that legitimately run past two minutes today starts failing after the upgrade with nothing documented to turn it off.
Not a code defect, and the PR states the default openly — but it is the largest exposure here by blast radius, and it should be an answered question rather than an implicit one before merge.
issue (non-blocking): MAX_BOUND_SECONDS javadoc is wrong twice, and the clamp is untested.
opendj-server-legacy/src/main/java/org/opends/server/backends/jdbc/JDBCStorage.java:330-341
* ... Clamped rather than refused, since this is 24 855 days and anything past it was meant as "no bound".
static final int MAX_BOUND_SECONDS = Integer.MAX_VALUE/1000 - BACKSTOP_MARGIN_SECONDS;2147483647/1000 - 30 = 2147453 s = 24.855 days, off by a factor of 1000. 24 855 days would be Integer.MAX_VALUE seconds. The difference matters: 25 days is a ceiling a deployment could plausibly configure and then silently receive a finite bound.
The stated reason is also false over almost the range it excludes — backstopMillis already does the multiply in long under a Math.min:
private static int backstopMillis(int seconds) {
return (int) Math.min(Integer.MAX_VALUE, (seconds+BACKSTOP_MARGIN_SECONDS)*1000L);
}Nothing below seconds = 2147483618 can overflow that; below the ceiling it simply returns Integer.MAX_VALUE, a valid timeout. The real reason to clamp is that setNetworkTimeout takes an int of millis — worth saying, since a reader who later removes the Math.min will believe clampSeconds still covers them.
No test touches either Math call; deleting both leaves the suite green. One assertion closes it:
assertEquals(JDBCStorage.clampSeconds(Integer.MAX_VALUE), JDBCStorage.MAX_BOUND_SECONDS);issue (non-blocking): startImport's new finally gives back the connection but not the storage.
opendj-server-legacy/src/main/java/org/opends/server/backends/jdbc/JDBCStorage.java:2196 vs :2214
The getConnection() catch got the storage close; the finally added in the same hunk did not, though the same sentence applies:
catch (Exception e) { if (!wasOpen) { close(); } throw new StorageRuntimeException(e); } // :2196
...
finally { if (!built) { try { con.close(); } catch (...) {} } } // :2214 — no !wasOpen close()An Error or RuntimeException out of the two transaction constructors on the !wasOpen path leaves the storage this method opened open forever, since ImporterImpl.close() is the only thing that would close it. That is exactly the class of failure the widening to finally was for. (ReadOnlyStorageException cannot co-occur — open(READ_WRITE) at :642-646 sets accessMode first.)
Also untested in either direction: testStartImportGivesTheConnectionBackWhenTheImporterCannotBeBuilt stubs getStorageStatus() to working(), so wasOpen == true and the :2196 branch runs in no test.
finally {
if (!built) {
try { con.close(); } catch (...) {}
if (!wasOpen) { close(); }
}
}suggestion (non-blocking): The null-value pin catches an incidental NPE.
opendj-server-legacy/src/test/java/org/opends/server/backends/jdbc/JDBCStatementBoundTestCase.java:979
catch (NullPointerException expected) { /* ... */ }The NPE comes out of ByteString.wrap(rc.getBytes("v")) (JDBCStorage:2016), not from anything the production code raises deliberately. Any unrelated NPE later introduced into positionToKey satisfies it, and if ByteString.wrap ever tolerates null the test flips from pinning to failing for an unrelated reason. Assert on the message or cause, or give the production path a named failure.
suggestion (non-blocking): The CLOCK_SLACK_MILLIS boundary itself is unpinned.
opendj-server-legacy/src/test/java/org/opends/server/backends/jdbc/JDBCStatementBoundTestCase.java:523
The two cases sit at 749 and 875 against a 750 threshold; neither sits at 750, so < vs <= in
if (elapsedMillis < endsAfterMillis - CLOCK_SLACK_MILLIS) { return e; } // JDBCStorage:602-607survives a flip. Moving one case to exactly the boundary closes it. Separately, the suite javadoc implies the 40001/1205 SQLState matters on this path; it doesn't — the classification is on elapsed time alone.
nitpick (non-blocking): getRecordCount's javadoc closes an enumeration that is wrong by six sites.
opendj-server-legacy/src/main/java/org/opends/server/backends/jdbc/JDBCStorage.java:1584-1586
One of the three places the class of the transaction is overridden downwards, the others being
openBulkCursor(TreeName)andCursorImpl.positionToLastKey().
StatementBound.BULK is also hard-coded at :1297, :1660, :1671, :1680, :1692 (openTree create table / create index ×3), :1723 (clearTree) and :1734 (deleteTree) — all inside WriteableTransactionTransactionImpl, whose bound is OPERATION on the write() path. Drop the count or name the DDL sites; the next reader auditing where an operation-class transaction can disarm the shared backstop will trust the list.
nitpick (non-blocking): ShardedCounter.getCount's javadoc names callers that call removeCount.
opendj-server-legacy/src/main/java/org/opends/server/backends/pluggable/ShardedCounter.java:125-129
A client operation reads a counter of its own —
numSubordinatesof a search, a delete, a modify DN — and takes the bound of one.
EntryContainer:1778 (delete) and :2208 (modify DN) call removeCount, not getCount. The actual 2-arg getCount callers are EntryContainer:750, ID2ChildrenCount:177 (getTotalCount) and VLVIndex:531 — and the list reads as exhaustive while omitting the last two, which is how the getTotalCount path stays invisible to whoever next decides the flag.
chore (non-blocking): Two PR-body corrections.
- The body still carries the justification this delta retracts:
BackendImpl.openBackend()logsNOTE_BACKEND_STARTEDwithgetEntryCount(), which is aselect count(*)over id2entry on every backend start.
The new javadoc at JDBCStorage:1578-1582 says the opposite and is correct — that count is RootContainer.getEntryCount():410 → getNumberOfEntriesInBaseDN0:2381 → id2childrenCount.getTotalCount(txn), which never reaches getRecordCount.
MAX_BOUND_SECONDSis a new behavioural ceiling the body doesn't mention; it states only that "0, or a negative value, leaves a class unbounded". A property set toInteger.MAX_VALUE— the usual "no bound" idiom — now yields a 24.9-day bound instead. Either say so, or map anything above the ceiling to 0.
…ss of the walk it measures ProgressTask reads a total before a verify walks the backend, and on the path a plain verify-index takes - cleanMode is set only where --clean named the indexes - that read was a client operation: one cursor on the counter tree, a scan and a sort of it where k cannot be an index key, under the 120 s of an entry read. It is built outside the try that guards the walk, so reaching the bound ended the job before its first record. getTotalCount() is now told which kind of work it belongs to, as getCount() already was, and cn=monitor, GroupManager and SubentryManager keep the class of a client. Three pins for it: the cursor of the walk form, the cursor of the client one, and ProgressTask asking the container for the former. The same read behind NOTE_BACKEND_STARTED is left with the client callers deliberately - it arrives through the public BackendImpl.getEntryCount() they share, which answers -1 for any failure rather than failing the open - and the javadoc says so rather than leaving it to be rediscovered. startImport() gives back the storage it opened when the importer cannot be built on it, as the borrow of the connection already did: ImporterImpl.close() is the only thing that closes a storage an import opened, so an Error out of the two transaction constructors left it open for good. A row that exists with no value fails through valueOfRow(), shared by read(), by positionToKey() and by the batch of a cursor, rather than through the bare NPE of ByteString.wrap that named neither the fault nor the table. A RuntimeException still, so that a corrupt row is never weighed against the bound of the statement that read it and reported as a timeout of a property that would have changed nothing. The batch is checked as its rows come off the statement rather than as they are handed out: buffered whole and unwrapped later, that row failed from advanceFromBuffer() - outside the bound and outside the catch of the batch that read it. MAX_BOUND_SECONDS is 24.9 days, not the 24 855 its javadoc claimed, and it is the ceiling of what a socket read timeout can hold rather than a guard of the arithmetic of backstopMillis() - the long multiply under the Math.min there covers that already, up to the int addition of the margin. It clamps down rather than out: Integer.MAX_VALUE bounds a statement at the ceiling instead of unbounding it, and 0 stays the way to say no bound. Five pins with those: the ceiling and the value it really arms, a failure exactly a slack under the bound - the point the two cases either side of it left free - the storage returned by startImport(), and the named failure of a null value in each of its three readers. The javadoc of getRecordCount() and of ShardedCounter.getCount() name the sites and the callers they have rather than counting them wrong: the first was three of ten, and the second named a delete and a modify DN, which reach removeCount, while omitting getTotalCount - which is how the branch above stayed invisible.
|
Thank you — the blocking issue was real, every non-blocking one was, and each line reference checked out again. All of it is in
|
…tement-timeouts The write transaction keeps the two constructors of OpenIdentityPlatform#877 - the statement bound a caller hands it - and takes the per-operation read-only check of OpenIdentityPlatform#874 in place of the refusal it replaced: super(con, bound) captures isReadOnly, and checkReadOnly() guards each mutating operation.
…tement-timeouts The statements OpenIdentityPlatform#877 gives the bulk class are exactly the ones OpenIdentityPlatform#879 now issues through commitStatement(), so the class moves into that method, and the importer keeps the constructor OpenIdentityPlatform#877 gave it while taking the validated connection OpenIdentityPlatform#879 asks an import to borrow.
Merged with master#876, #880 and #883 have all landed, and this branch is merged with them. Two of the conflicts were
Also worth flagging: one line of Out of scope in the description had gone stale — a read timeout
The blocking point of the last round — |
…ain, and take every borrow through one method The write transaction of a read-only storage stopped throwing when OpenIdentityPlatform#874 replaced the refusal in its constructor with a check per operation - which RootContainer.open() needs, and which an import does not: the merge with master left startImport() handing out an importer for a storage that is not writeable, one that would take a connection, begin its transaction and fail at the first tree it clears rather than at its start. An import writes by definition, so ImporterImpl refuses such a storage where it is built, which is where it was refused before that change. What reaches it is a storage that was already open: import-ldif and rebuild-index close it first, and startImport() opens a closed one READ_WRITE. And both borrows of this storage go through getConnection(boolean): OpenIdentityPlatform#883 moved startImport() onto getValidatedConnection(), which a test standing in for getConnection() no longer intercepted, so the two tests of that path reached for a real database - the connection string of a mock configuration - instead of the connection they had prepared.
|
@maximthomas the merge of the previous comment broke two tests, and
1. The import path lost its refusalThe merge note said the write transaction "takes the per-operation read-only check of #874 in place of the refusal it replaced". That is right for a transaction —
Said plainly, because it is the first thing worth attacking: that refusal is reachable only for a storage that is already open read-only. 2. The stand-ins for the pool stopped being reachedIndependently of the above, #883 (#879) moved
Four things found while fixing this, none of them touched hereNamed rather than fixed, because none is a regression of this branch and each is a decision of its own:
Happy to file them as an issue if you would rather they did not sit in a comment. Runs
|
…tement-timeouts The conflicts are all against the compressed schema trees of OpenIdentityPlatform#873 (OpenIdentityPlatform#881), resolved so that both rules hold at once: * JDBCStorage: every read path takes the non-enrolling readTableName() and keeps the statement class this branch gives it, so read(), getRecordCount() and the cursor no longer enrol a tree they only read, and are still bounded by the class of the work they belong to. * JDBCStorage.isExistsTable(): kept where master moved it - on the readable transaction, so the migration probe of OpenIdentityPlatform#873 can neither create nor enrol the shared tree - with the OPERATION bound of this branch. It reads a data dictionary rather than the data, so a wait there is another session's metadata lock whoever asks. * PersistentCompressedSchema: load() became loadTrees() guarded by treeExists(); each walk keeps its bulk class, and the migration walk master added takes one too - it reads a whole legacy tree while the backend opens, with nobody waiting on it. * jdbc/TestCase: both sides appended methods at the same place; both sets kept. * BulkCursorTest: follows the new backendId parameter of PersistentCompressedSchema and stubs the treeExists() that now guards both walks.
|
@maximthomas #881 (#873) and #894 (#890) have landed and this branch is merged with them —
|
|
CI has finished on the merge — run 33610234970 on The four engine suites did run against real containers rather than skipping, which is the part of the previous comment that was still a promise:
Two stale lines in the description are corrected with it: the engine counts under Tests were still the 55/55 of before these merges, and the note closing the #876/#880/#883 section said the suites had not been re-run — they have been now, and against everything since. |
…bounded OpenIdentityPlatform#882 landed, and the two branches had moved the same borrow in different directions. Resolved so that the design of this one stands and what OpenIdentityPlatform#877 gave that path comes with it: * The importer keeps the borrow this branch moved into its constructor, and startImport() is collapsed to match. git flagged only the constructor - it had auto-merged startImport() to master's version, which borrows before building the importer - so taking the conflicted side alone would have borrowed twice. * Both transactions of the importer keep StatementBound.BULK: every statement an import issues is bulk by construction, which is the contract of OpenIdentityPlatform#877. * The ReadOnlyStorageException of OpenIdentityPlatform#882 stays, inside the try rather than in front of it, so a storage this constructor opened is given back when the refusal fires. * One seam for the borrow (OpenIdentityPlatform#882) naming the pool this storage registered with (OpenIdentityPlatform#878): getConnection(boolean) goes through poolKey(). The refusal now stands in front of the borrow, so an import of a read-only storage takes no connection at all rather than taking one and returning it. The two tests of OpenIdentityPlatform#882 that pinned the return are rewritten to pin that nothing is borrowed - the same leak, covered at the state that cannot reach it.
…e-catalog OpenIdentityPlatform#882 landed, and the three conflicts are the same statements bounded there and rewritten here. Resolved so that this branch keeps what it does and each of those statements keeps the class OpenIdentityPlatform#877 gave it: * removeStorageFiles() keeps the catalog-driven loop of this branch; the bulk class OpenIdentityPlatform#882 put on the drop it replaces is given once, inside dropTable(). * The readable transaction keeps its delegation to the scoped lookup; the operation bound OpenIdentityPlatform#882 put on the body it replaces moves to that lookup - a catalog read, so a wait there is another session's metadata lock whoever asks. * isExistsIndex() takes both: the scope narrowing of this branch and the operation bound of OpenIdentityPlatform#882. Two the merge did not mark: * readCatalogRows() read from a live ResultSet through the one-argument executeResultSet() that OpenIdentityPlatform#882 removed, so it did not compile. It reads the rows inside the bound now, as OpenIdentityPlatform#882 converted every other such site, and takes the same operation class they took. * createCatalogTable() issued its create table through execute(statement), which carried no bound before OpenIdentityPlatform#882 and would silently have taken the class of a client operation after it. Bulk, like every other create table of this backend: it is DDL nobody waits on.
…dlock-retry-window OpenIdentityPlatform#877 (OpenIdentityPlatform#882) has landed and touches the same file. Two things had to be decided: * The import block: TimeUnit of this branch beside the Executor and AtomicBoolean of OpenIdentityPlatform#882, all three kept. * nanoTime(). Both branches added the same overridable clock to JDBCStorage, with the same signature and the same body - OpenIdentityPlatform#877 to classify a statement that reached its bound, this branch to measure the retry window of write() - at opposite ends of the file, so git marked nothing and the merge did not compile: "method nanoTime() is already defined in class JDBCStorage". One method now, with a comment naming both of the things measured on it. Compiles, and JDBCStorageRetryTest (89), JDBCStatementBoundTestCase (37), CachedConnectionTestCase (64), StampConnectionTestCase (5), BulkCursorTest (12) and PersistentCompressedSchemaTest (8) pass - 215 together.
… one is bounded, and account for a catalog row a clear cannot act on Answering the sixth review round: * The catalog connection reads org.openidentityplatform.opendj.jdbc.connect.timeout, the property the pool bounds its own connects by, instead of the pool's default, and honours 0 as the operator asking for no bound of the connect. A deployment which had raised that property because its login is slower than the default met a second, tighter bound here, and 08001 is no conflict write() replays: the backend stopped opening on an installation that opened before this connection existed. What is not taken from the pool is the deadline of the borrow, and the javadoc says what that costs at a property of 0 rather than claiming parity. * A row of the catalog the read passes over - one naming no tree, one naming something that is not a tree name, one recording a table outside the namespace this backend names its tables in - was named by no line of the clear's report: what such a row records is outside the "opendj" names the leftover scan walks, and the row itself is dropped by nothing. The clear counts and lists them now. * PgSqlTestCase asserts the second half of what the search-path narrowing decides: an open of the storage whose connections resolve in a schema ahead of the tables creates no second, empty table there to shadow the populated one. The lookup half was covered; this one is the destructive one and was asserted by nothing. * A comment of testTheSharedCompressedSchemaTreesAreNamedButNeverCleared that OpenIdentityPlatform#881 had made false is rewritten. It argued for deleting the hand-drop the case needs, which testCompressedSchemaTableIsQualifiedByBackendId then fails on whenever TestNG runs it second. * CatalogConnectionTestCase covers the establishment of the catalog connection, which no test reached at all: the bound of its connect, the default, the property at 0, the set-up of the connection and the close of one whose set-up failed. Its two cases about the bound fail on the previous head. JDBCStorageRetryTest asserts the enrolment on that connection - the create, the row and the commit - where every assertion it had held of a storage that enrolled nothing whatever, and TestCase covers the skipped row on all four engines. And a code review of the same head: * CatalogSession.reset(), StampSession.reset(), enrolInCatalog(), readEnrolledTrees() and createCatalogTable() caught SQLException alone, where unenrolFromCatalog() had always taken both. An unchecked failure skipped the rollback and left the shared catalog connection in 25P02 for the twenty-odd enrolments behind it, with a cause nowhere near the one that started it - and in createCatalogTable it skipped the tolerance of a table another session had just created, turning a benign race into a failed open. * The postgres search-path probe takes the operation bound of OpenIdentityPlatform#882, like the lookups the scope it builds narrows. The savepoint and the fallback answer for a query this engine refuses, not for one it never answers at all: that was a wait holding the open of a tree with nothing able to end it, and the one statement of this class outside the bounds of OpenIdentityPlatform#877. * A failed catalog connect is reported through CachedConnection.reported(), which is what keeps the password of a connection string a driver echoed back out of ERR_OPEN_ENV_FAIL. * The backend id goes into the name of the catalog tree escaped the way PersistentCompressedSchema escapes it into its own prefix. TreeName.valueOf splits on the last slash, so an id carrying one named a tree that does not survive being read back, and a clear could not recognize the stamp of its own catalog table. An id of the ordinary shape is unchanged, so no table of an installation is renamed by this. * listTrees() borrows a validated connection: since it answers from the catalog it is one of the paths that issue their statements far from the borrow and compensate a dropped connection in no other way. * readEnrolledTrees() asks through the non-enrolling name of OpenIdentityPlatform#881 - reading what the catalog records is not taking an interest in the tree it names - and two statements about tree2table that this branch had made stale are corrected. Tested: 178 of 178 of the non-container suites, and against containers PgSqlTestCase 76 of 76 and MySqlTestCase 75 of 75, Skipped 0 on both.
Problem
Not one statement of the JDBC backend was given a
setQueryTimeout: nineteen sites inJDBCStorageprepared a statement and waited for the database indefinitely. A row locked by an unrelated session, a table waiting for a metadata lock, or a database that stops answering mid-query parked the worker thread that issued it for good, with nothing in the log to say so.This is the half of #872 that lives behind a successful login. #876 bounded the establishment of a connection; a statement on a connection that is already through was, until now, the one unbounded phase left — and deliberately so, since the read bound of the login is lifted once the login is over, because leaving it in place would fail every statement slower than it.
Change
The bound goes on the statement, not on the session. Setting the engine's own
statement_timeout/MAX_EXECUTION_TIME/LOCK_TIMEOUTonce per connection would be cheaper, but a pooled connection cannot carry a session setting:CachedConnection.close()only rolls back, so whatever one operation set would apply to whoever borrows the connection next — the same reason #866 gives its comment statements a connection outside the pool. All execution sites already went throughexecute()/executeResultSet(), so that is where the bound is applied.One value cannot serve every call site, so the bound is per class of statement:
OPERATIONput/update/delete, the batches a cursor walks for a client, the VLV offset ofpositionToIndex(), the catalog lookups ofopenTree()org.openidentityplatform.opendj.jdbc.query.timeoutBULKselect count(*), thedelete fromofclearTree(), theorder by k descbehindpositionToLastKey(), every statement an import issues, every batch of a cursor opened for a walk of a whole tree together with the reads that walk makes,create table,create index,drop tableorg.openidentityplatform.opendj.jdbc.bulk.timeoutanalyze/dbms_stats.gather_table_stats/update statisticsafter an importorg.openidentityplatform.opendj.jdbc.statistics.timeout0, or a negative value, leaves a class unbounded, exactly as this backend ran before; a value that is not a number is ignored in favour of the default, asInteger.getInteger()has it, so a typo cannot silently unbound a class. A value above 24.9 days is taken down to it rather than read as another way of saying "no bound": that is what a socket read timeout can hold —setNetworkTimeouttakes milliseconds of anint— soInteger.MAX_VALUE, the usual "no bound" idiom, bounds a statement at the ceiling instead of unbounding it. Clamping down rather than out is the direction that never takes a bound away from a deployment that asked for one, and at 24.9 days it cancels nothing a database will not have ended first.So not every statement ships bounded, and the title says the class rather than the statement for that reason. The bulk class ships at
0and a class with no bound takes neither layer: what such a statement legitimately needs follows the size of the backend and the speed of its database, neither of which can be guessed here. Three of those run with no operator watching —PersistentCompressedSchemaandID2Entry.afterOpen()walk their trees whilestart-dsopens the backend, andExportJobwalks the whole of id2entry behind the generation ID a replicated domain computes the first time it starts — so on a blocked table they wait as this backend waited before any of these bounds existed. That is the deliberate half of the trade: the only other value there was to give them is the bound of a client operation, and bounding them that way stopped a large backend from opening at all. A deployment that wants them bounded sets the bulk property, which bounds the import statements with them; a bound of their own is follow-up material rather than a knob added here on a guess.The split is not theoretical:
AbstractTwoPhaseImportStrategy.beforePhaseOnecallsclearTree()for every tree before an import writes its first record, andselect count(*)is a scan of the whole table on every engine here for whoever asks —dbtestthroughBackendStat, and the countsverify-indexreports. (It is not the count behindNOTE_BACKEND_STARTED: that one isRootContainer.getEntryCount(), which sumsid2childrenCountand never reachesgetRecordCount. An earlier revision of this description said otherwise.)positionToLastKey()belongs to the same class for the same reason: it has no key to seek on, so it is anorder by k descover the whole table — a scan and a sort of it on SQL Server, wherekis avarbinary(max)that cannot be an index key — andRootContainerruns it once per base DN throughEntryContainer.getHighestEntryID()on every open of a backend, outside the try/catch ofBackendImpl.openBackend(). A single 120-second default would have broken the start of a large backend and everyimport-ldif.The default of the operation class also sits above the lock timeout of the engines, which matters for the transaction replay of #867: MySQL surfaces contention as class 40 through
innodb_lock_wait_timeout(50 s) and that has to stay a replayable conflict rather than become a cancelled statement.The class follows the work, not the shape of the statement. An import issues the same
selectand the same upsert a client operation does; what differs is that nobody is waiting on it, and that on SQL Server it works the table unindexed. So the class belongs to the transaction: the two anImporterImplholds are bulk, and with them every statement an import issues —put()throughupsert(),read(), and the batches of the cursor phase one walks (OnDiskMergeImporter.ID2EntrySource). Only the catalog lookups ofopenTree()keep the operation class whoever runs them: they read a data dictionary rather than the data, so a wait there is another session's metadata lock, which is one of the waits this bound exists to end.The same holds inside a walk.
verify-indexwalks dn2id whole and reads the children count of every DN it passes (VerifyJob→ID2ChildrenCount.getCount→ShardedCounter), then walks the counter tree whole and asksID2Entry.containsEntryID()of every record in it. Those are one cursor per DN and one per record, inside a job nobody is waiting on, so they take the class of the walk rather than of a client operation — while the same counter read made by a search asking fornumSubordinates, or by a VLV index reporting its size, stays exactly what it is (a delete and a modify DN reach neither form: they go throughremoveCount).containsEntryID()has no caller but that walk, so it is bulk outright;getCount()is told which of the two it is.And so is the count that sizes that walk.
ProgressTaskreads a total before the first record is verified, and on the--cleanpath it reads the record count of the tree being verified, which is bulk by the tree it counts. The other path — a plainverify-index, with or without an index named, which is what an operator runs — readgetNumberOfEntriesInBaseDN0()as a client operation: one cursor on the counter tree, and on SQL Server a scan and a sort of it, under the 120 s of an entry read. It is built outside the try that guards the walk, so reaching that bound aborted the whole job before its first record — the job #877 exists to protect.getTotalCount()is now told which of the two it is, the same waygetCount()is, andcn=monitor,GroupManagerandSubentryManagerkeep the client class they should have.A walk of a whole tree asks for it through the SPI.
ReadableTransaction.openBulkCursor()is adefaultmethod answering exactly asopenCursor(), so every engine that bounds nothing — JE, PersistIt, Cassandra — inherits it unchanged, and only the JDBC backend gives it a class of its own. What asks for it is what walks a tree whole with no client waiting:ExportJob, the whole-tree passes ofVerifyJoband the reads they make as they go, the tree and index dumps ofdbtest, the load of the compressed schema, and the read that checks id2entry is there. Reading the class off the statement instead would not do: the opening batch of every cursor is the same unconditionedorder by kthatpositionToLastKey()issues, so it would either unbound the first batch of every search or bound the walk of an export as if a client were waiting on it.Two of those have nobody at a command line, which is what makes this a bound that has to be right rather than a preference:
ID2Entry.afterOpen()reads the first batch of a cursor over id2entry on every open of a backend (EntryContainer.open()←RootContainer.openAndRegisterEntryContainers()←BackendImpl.openBackend());LDAPReplicationDomain.loadGenerationId()computes the generation ID of a domain the first time it starts —computeGenerationId()→exportLDIF()→ExportJob, a walk of the whole of id2entry.On SQL Server, where every batch of such a walk is a scan and a sort of the table, both of those failed at two minutes on a backend large enough.
The rows are read inside the bound.
executeResultSet()hands the rows to its caller instead of returning a liveResultSet, so the transfer runs while the bound is still armed. A driver hands rows over as they are asked for, andsetQueryTimeoutcoveringResultSet.next()is optional in the JDBC contract ("drivers may also apply this limit"): PostgreSQL and MySQL buffer a result whole and are not affected, but Oracle prefetches ten rows against batches of a thousand and SQL Server buffers adaptively, so a drain outside the bound is a wait with nothing bounding it — on SQL Server that is #877's own symptom, since aselectunder READ COMMITTED really does block on a row another session holds.Two layers, because the first one is not answered everywhere.
setQueryTimeoutcancels the statement and keeps the connection — every driver implements it by cancelling, not by a socket timeout: pgjdbc opens a connection of its own to send a CancelRequest, mysql-connector-j issuesKILL QUERY, and ojdbc and mssql-jdbc send a break on the same socket. Behind it, a socket read timeout is armed for the duration of the statement and released afterwards, so the wait ends even when the cancel is not acted upon.Oracle is why that second layer exists, and the container suite is what found it: with
setQueryTimeout(5)the blocked write ran for the full 600 s of the test harness, parked inSocketDispatcher.read0underOracleStatement.doExecuteWithTimeout— the timeout was armed and never arrived, because a session blocked in a row-lock enqueue does not process the break its driver sends. Reaching the second layer costs the connection (the driver closes it), which is the price of a wait the database was never going to end on its own.That second layer belongs to the connection, not to the statement, so it is arbitrated between the statements running on one. A socket read timeout is a property of the socket, and this backend does share a connection: an
Importerholds a single one for the whole of an import and writes to it from every phase-one worker and every phase-two task. Armed and released per statement there, the first statement to finish would take the backstop away from every statement still in flight, and a statement of a class carrying no bound would run under whatever value a concurrent one happened to arm — dying at a bound it was never given, and naming no property for it, since such a statement never reaches the classification below.So the value armed is the loosest of the bounds of the statements in flight, a statement with no bound of its own takes the backstop off for as long as it runs, and what the connection carried before is put back when the last of them is through. The state is kept per physical connection, by identity:
CachedConnection.prepareStatement()hands the statement to the connection it wraps, so that is the one a statement reports, while the catalog lookups hold the wrapper of that same connection — both unwrap to the same entry, and an entry lives only while statements are running on its connection.It only ever tightens: it is armed when the connection carries no read timeout at all - 0, "no timeout" in the JDBC contract - or one looser than itself, and where nothing is changed nothing is put back afterwards. What it does arm, it always gives back: a connection whose driver refuses the call mid-flight, and one still armed when the storage gives this layer up altogether, are both put back to what they carried before. A pooled connection that kept ours would go back to the pool wearing it as its own, and the next borrower — which only ever tightens — would read it as a value of a deployment and keep it from then on. Being the cancel's bound plus a margin, it is the looser of the two by construction, so setting it unconditionally would have replaced a read timeout a deployment gave its connections (the setting #885 asks for) exactly while a statement was running.
It is also the only layer the catalog lookups of
openTree()can be given:DatabaseMetaData.getTables()andgetIndexInfo()take no query timeout, and they run once per tree on every open, behind the same locks as thecreate tablethey guard.The statistics refresh keeps a property of its own, under both layers. It is not a class of
StatementBound: what it takes follows the size of the table it describes, so a class would put 120 s over a statement its own property allows 600. It does need the second layer, and on the engine that most needs it — on Oracle this isdbms_stats.gather_table_stats, and it runs at the very end of a successful import, where a cancel that is not acted upon would parkimport-ldifwith the data already committed and nothing left to report.A driver that will not take one of the two layers keeps working, and says which one it is.
setQueryTimeoutraisingSQLFeatureNotSupportedExceptiondegrades to the socket read timeout behind it, with one warning, rather than failing every statement. A driver with no network timeout at all says so the same way, and that is remembered for the storage — the scope of a driver — while a connection that merely failed the call, which is most often one on its way out, is remembered only while its own statements run and never speaks for the connections that are healthy. Each cause has a warning of its own.A failure before the bound is passed through untouched, so a lock wait reported in class 40 stays the conflict a caller can replay. One that arrives at the bound is wrapped in a
SQLTimeoutExceptionnaming the property that produced it — no driver knows why it was cancelled, and every one of them reports a cancellation differently (PostgreSQL 57014, Oracle ORA-01013, and neither of them as aSQLTimeoutException), so the bound is recognized by the time the statement took, measured on the monotonic clock, rather than by the class or the state of its failure. Where the cancel is not in force — aDatabaseMetaDatalookup takes no query timeout, and a driver may refuse one — the statement is measured against what the socket read timeout really armed for it, rather than against what the property says that layer would have been. Asking for a layer is not having it: a driver with no network timeout, a connection that failed the call, one already carrying a tighter timeout of a deployment's own, and a statement of an unbounded class running beside this one each leave it unarmed, and a statement neither layer bounded reached no bound of ours at all. Its failure is the driver's own and is passed through exactly as it is — naming a property that armed nothing sends an operator to raise a value that changes nothing about the wait they watched. The SQL state and the error number are carried over, and the failure being replaced is chained. The statement itself is left out of the message: a driver renders it with its parameters bound, and those are entry data.Two things the move of the rows inside the bound touched, put back as they were.
positionToKey()now wraps the row inside the handler rather than after it, sonullkeeps meaning "no such key" and only that: read outside, a row whosevis null - which the schema allows, however this backend writes it - reported a key that exists as absent instead of failing the wayread()still fails on it. Both go throughvalueOfRow(), which names that failure rather than leaving it the bareNullPointerExceptionofByteString.wrap— aRuntimeExceptionstill, so that a corrupt row is never weighed against the bound of the statement that read it and reported as a timeout of a property that would have changed nothing. So does the third reader of a value, the batch of a cursor, and there the check is made as the rows come off the statement rather than as they are handed out: a batch is buffered whole, so left toadvanceFromBuffer()the same row would have failed outside the bound, outside thecatchof the batch that read it, and as exactly the bare NPE this replaces. AndstartImport()gives back what it borrowed on every path that does not build an importer to hold it — through afinallyrather than acatch, so anErroris covered asReadOnlyStorageExceptionis: the connection an import would have kept for its whole duration was leaving the pool for good with the transaction it had already begun. The storage goes back with it, on the branch where this method opened it:ImporterImpl.close()is the only thing that closes a storage an import opened, so a failure between the open and the importer that would have held it left it open forever — which the borrow was already covered against and the build was not.A bound is clamped to what the second layer can hold, 24.9 days, since
setNetworkTimeouttakes milliseconds of anintand a bound past that has no value of that layer to be given. Not for the arithmetic:backstopMillis()does the multiply inlongunder aMath.min, and only adding the margin inintseconds, which needs a property within 30 ofInteger.MAX_VALUE, can overflow it into the negative timeout every driver refuses. The ceiling is a ceiling of the layer, not a guard of that sum — worth saying, since a reader who later drops theMath.minmust not read the clamp as covering them.Tests
JDBCStatementBoundTestCase— 37 tests, no database, 8 s, one storage per test so that a latch meant to be one-shot for the life of a storage cannot silence the assertions of the tests after it: the defaults, that each class follows its own property, that a value which is not a bound leaves the statement unbounded while one that is not a number falls back to the default, that the bound reaches the statement and that an unbounded class costs no call at all, that the rows are read while the bound is still armed and a failure during that transfer is measured against the bound, that a driver without a query timeout keeps working under the backstop alone while one without a network timeout is asked once and a connection that failed the call is asked again, that a catalog lookup is bounded and that a failure inside the margin of the layer bounding it is passed through, that the scan behind the highest entry id is bulk while the batches a client walks are not, that a cursor opened for a walk of a whole tree takes bulk batches, that every statement of an import is bulk, that the statistics refresh runs under its own bound and the backstop, and the classification branches: a failure inside the bound arrives as the very instance thrown, one at the bound names the property and keeps its SQL state, one reported a few milliseconds under the bound — a driver keeps its timer in whole seconds — is still the bound and names it too while one a millisecond further out is not, and the message reports the time the statement really took rather than the bound it reached, which on Oracle is a margin later than the property that armed it. Those last two run on a clock the test drives rather than on a sleep: the classification turns on a few milliseconds either side of the bound, and a sleep that a loaded box lengthens pins nothing while staying green.Three of them are about the layers being told apart: that a statement neither layer bounded is passed through untouched, that a connection whose driver refuses the call is given back what it carried, and — with the rows of the delta this round — that a row whose
vis null fails rather than reporting the key as absent — inpositionToKey(), inread()and in a batch of a cursor alike, and by the named failure ofvalueOfRow()rather than by whatever null reaches first. And thatstartImport()returns its connection when the importer cannot be built, and closes the storage it opened on the branch where it opened one: the connection half pins the designed path rather than the widening tofinally, sinceReadOnlyStorageExceptionis aRuntimeExceptionand thecatchit replaces covered it already, while the storage half goes red without the delta of this round.Four more come with this round: that a bound above what the second layer can hold is taken down to the ceiling rather than read as no bound at all — pinned on the value really armed, so that dropping either
Mathcall is caught — and that a failure exactly a slack under the bound is still the bound, which is the point the two cases either side of it leave free.Six of them are about a connection carrying more than one statement at a time, which is what an import does — the import test among them, since its statements now report the connection they run on and so really reach the second layer instead of stopping at the first — all on two threads, since that is the only way one statement outlives another: that the backstop is armed and put back, that it never loosens a tighter bound the connection already carries, that a statement of an unbounded class takes it off while it runs and gives it back afterwards, that it outlasts the statement that armed it, that with two bounds in flight the loosest is what is armed, and that a looser bound joining re-arms it and the tighter one gets its own back when the looser statement leaves.
ID2EntryTest— the read that checks the tree is there when a backend opens asks for a bulk cursor, the call site of this branch that no operator is standing at.BulkCursorTest— 12 tests, no database, 3 s: which cursor each walk of a whole tree asks for, pinned twice — that the bulk cursor is what it asks for, and that it asks for no cursor of an operation at all.ReadableTransaction.openBulkCursor()is adefaultanswering exactly asopenCursor()does, so a call site turned back would compile, run, and stay invisible on every engine but this one.Six call sites are pinned through their own caller:
ExportJob(the generation-ID walk), the id2entry, dn2id and VLV walks ofVerifyJob, and both trees ofPersistentCompressedSchema. The dn2id one walks a tree holding a record, so the walk really runs its body and the counter read inside it is pinned with it — over an empty tree the loop stops before its first row and everynever()below it passes on a run that reached nothing. Three more are pinned through the delegation rather than the caller, which is all that is available for them:DefaultIndex,ID2ChildrenCount/ShardedCounterandID2Entry.containsEntryID(). The count that sizes the progress report of a verify is pinned one hop above its cursor — on the container,ProgressTaskreading it throughgetNumberOfEntriesInBaseDN0()— with the cursor of that read pinned both ways below it: bulk for the walk, an operation for the client that reads the same total. AndVerifyJob.iterateID2ChildrenCount()is pinned by the compiler:ID2ChildrenCountexposes no cursor but the bulk one — the deadopenCursor()overload it kept is deleted — so that revert does not build.Three call sites are left uncovered and named in the suite rather than passed over: the attribute index of
verify-index, whoseMatchingRuleIndexisfinaland cannot be handed to a mock, and the two ofdbtest. All three walk a tree only on the command line of an operator. Named with them is what no call site pins at all: the single-rowReadableTransaction.read()those same walks make, once per row of dn2id and of a VLV index, which has no bulk form in the SPI and takes the class of the transaction it is made through — a gap of the SPI rather than a call site anyone can revert, and one that risks a lock wait rather than a walk cut short.TestCase.testWriteBlockedByAnotherSessionGivesUpAtItsBoundandtestBulkStatementGivesUpAtItsOwnBound— another session holds every row of the tree in an uncommitted transaction, and the operation under test has to give up inside its bound. Only the class being tested is bounded and the other is set to 0, so a pass cannot be credited to the wrong property. The bulk case goes throughImporter.clearTree(), which is where thedelete from <table>of that class is reachable. Both assert the window of the bound — from the bound itself to what the bound really allows a statement, which is the second layer rather than the property, sinceholdBackstop()arms the socket read timeout at the bound plus its margin on every engine and not only on Oracle — and that the failure names the property that produced it, so a run that gives up at MySQL's own 50-secondinnodb_lock_wait_timeout, or falls over at once for an unrelated reason, fails the test. They also assert which layer ended the wait, because a ceiling wide enough for the second one cannot tell a working first layer from a missing one: a driver that stops takingsetQueryTimeoutdegrades to the backstop by design and silently, ends there, and would otherwise be scored as the bound doing its work.timedOut()names the layer, and the suite reads it off the message through a constant shared with it. The window is measured on the monotonic clock, astimedOut()measures the bound.All four container suites pass with no skips — PgSql, MySql, MsSql and Oracle 62/62 each on the current head (the counts have grown with the suites the merges below brought in). The blocked write, given a 5-second bound, gives up at it on PostgreSQL, MySQL and SQL Server, and at the bound plus the 30-second margin of the second layer on Oracle — the cancel being ignored there and the socket read timeout ending the wait. No measurable overhead across the change: the suites stay within container noise of where they were.
Out of scope
Two refinements are not covered here, rather than stretched into a branch that cannot reach them. They are filed as #885:
CachedConnection.relaxReadBound(), which only exists on the branch of [#872] Bound the connect of the JDBC pool and report a connect it cannot make #876, so a branch off master cannot touch it without conflicting. The second layer above covers the same failure for the duration of a statement, which is when it matters;CachedConnectionagain), or it costs a round trip per transaction. With the statement bounded the hang is already over; what remains is a more precise error and, on the engines that report a lock wait in class 40, a replayable one.commit()takes no bound of any kind and is left as it stands. So are the two statements that run on a stamp connection — the comment statement of #866 and the session setting (set lock_timeout/alter session set ddl_lock_timeout) issued when that connection is established: a stamp connection is given a lock timeout of its own and a socket read timeout in its connect properties.Follow-up to #872 / #876.
Fixes #877
Merged with master (#876, #880, #883)
The three PRs this branch was waiting behind have landed, and the merge had to decide two things
rather than only separate two edits:
commitStatement(). [#879] Skip the validation of a pooled JDBC connection returned a moment ago #883 (JDBC backend validates the pooled connection on every borrow, costing a database round trip per operation #879) replaced theprepareStatement/execute/commitofopenTree(),clearTree()anddeleteTree()with a singlecommitStatement(sql, ddl)that raisespartlyCommittedon the side each engine commits on. Thosecall sites are exactly the list this PR names as overridden downwards — the
create tableand thethree
create indexofopenTree(), thedelete fromofclearTree(), thedrop tableofdeleteTree()— so the class is given insidecommitStatement()(execute(statement, StatementBound.BULK)) instead of at each site. Nobody waits on any statement that reaches it.ImporterImpl(con, StatementBound.BULK)stands as this PR wrote it, so both transactions of an import are still bulk byconstruction;
startImport()borrows throughgetValidatedConnection(), which JDBC backend validates the pooled connection on every borrow, costing a database round trip per operation #879 asks of animport for the same reason it asks it of an open — the statements come far from the borrow.
checkReadOnly()of #880 (#874) and the two constructors of this PR meet in the write transaction:super(con, bound)capturesisReadOnly, and each mutating operation is guarded per call rather thanthe transaction being refused outright. That is right for a transaction and wrong for an import, and
the suite said so: with the refusal gone from the constructor,
startImport()handed out an importer fora storage that is not writeable, and the two tests of that path failed on the merge (
build-maven (ubuntu-latest, 21)of run 33504253623).0f1b576puts the refusal where the importer is built - animport writes by definition, so
ImporterImplrefuses such a storage there, which is where it wasrefused before #874 - while the write transaction keeps exactly what #874 gave it. What reaches that
refusal is a storage that was already open:
import-ldifandrebuild-indexboth close the storagefirst, and
startImport()opens a closed oneREAD_WRITE, so the refusal stands where the old onestood rather than where an import of any storage of this server would meet it.
The same commit takes both borrows of the storage through one method. #883 (#879) moved
startImport()ontogetValidatedConnection(), which does not go throughgetConnection(), so thestand-ins those two tests install for the pool stopped being reached and the tests borrowed for real -
against the
jdbc:postgresql://localhost/testthat a mock configuration answers with.getConnection()and
getValidatedConnection()now both delegate togetConnection(boolean trusted), which is the oneplace a stand-in has to intercept.
One line of Out of scope above has gone stale with #876 landing: a read timeout for an established
connection is no longer unreachable from a branch off master —
CachedConnection.relaxReadBound()isin master now. It stays out of this PR all the same, as #885.
mvn -pl opendj-server-legacy test-compileis green, and so isJDBCStatementBoundTestCase(37/37)with
JDBCStorageRetryTest,CachedConnectionTestCaseandStampConnectionTestCasebeside it(135/135). The four engine suites were not re-run at the time of that merge; they have been since — see the section below.
Merged with master (#881, #894)
#881 (#873) gives each backend its own pair of compressed schema trees; #894 (#890) persists a token
before handing it out. #894 came through cleanly. Every conflict was against #881 — four in
JDBCStorage, two inPersistentCompressedSchema, one interleaved block injdbc/TestCase, and onethe merge did not mark at all.
tree maps to in two:
getTableName()enrols the tree intree2table, which is whatremoveStorageFiles()drops, whilereadTableName()answers without enrolling — so a tree thisbackend does not own, the shared pair the migration of JDBC backends sharing a database URL share one pair of compressed-schema tables #873 reads, is not put up for removal by
being read.
read(),getRecordCount()andCursorImplare the three sites both PRs edit, andthe two edits are independent: one decides which table the statement names, the other how long it
may take. Neither side's line carried both, so each was rewritten to. Master's
getRecordCount()would not have compiled here in any case — this branch removed the single-argument
executeResultSet()that returns a liveResultSet, which is what puts the row transfer insidethe bound.
isExistsTable()keeps master's place and this branch's bound. [#873] Give each backend its own compressed schema trees #881 moved it from thewriteable transaction up to the readable one, so the probe of JDBC backends sharing a database URL share one pair of compressed-schema tables #873 — made from the writeable
transaction of
RootContainer.open()— can neither create nor enrol the shared tree. The boundgoes with it, and stays hard-coded
OPERATIONrather than taken from the transaction that happensto ask: it reads a data dictionary rather than the data, so a wait there is another session's
metadata lock whoever runs it. That is the rule this description already states for the catalog
lookups of
openTree().load()intoloadTrees(txn, ocTree, adTree), called twice and each walk now guarded bytreeExists(); both keep the bulk class this PR gave them.copyMissingRecords()— the walk [#873] Give each backend its own compressed schema trees #881adds, which copies the legacy definitions into the backend's own pair — takes one it never had: it
reads a whole legacy tree while the backend opens, with nobody waiting on it, which is the rule the
bulk class exists for. Left at the operation class it would be the same failure this description
names for
PersistentCompressedSchemaabove, on the one open where there is most to read. This isthe merge extending a rule to code that did not conflict with it, and is called out here for that
reason.
BulkCursorTest.testTheCompressedSchemaIsLoadedWithBulkCursorsis new on this branch and
PersistentCompressedSchema's constructor is changed on master: atextual conflict in neither file, and a compile error in the merge, [#873] Give each backend its own compressed schema trees #881 having added the
backendIdthat qualifies the trees. The test also had to stubtreeExists()— the walks it pinsare guarded by it now and a mock answers
false— so it fails outright without the stub ratherthan passing on nothing. With the stub, reverting either
openBulkCursorinloadTrees()reddensit and only it (12 run, 1 failure).
jdbc/TestCaseneeded no decision: both sides appended methods at the same point and both sets arekept — this branch's 194 lines onto master's file, nothing dropped either way.
CI is green on the merge (
bdcbea9, run 33610234970): 32160 tests, 0 failures, 0 skips acrossthe whole matrix. The four engine suites ran against real containers and pass 62/62 each — PgSql,
MySql, MsSql, Oracle — with
EncryptedTestCase35/35,JDBCStatementBoundTestCase37/37,JDBCStorageRetryTest66/66,CachedConnectionTestCase64/64,StampConnectionTestCase5/5,BulkCursorTest12/12 andPersistentCompressedSchemaTest8/8 beside them.