[#885] Bound the wait of a JDBC DDL for a lock another session holds - #936
Conversation
…other session holds The DDL of this backend is the part of it that takes locks, and three engines out of four wait for one essentially forever: lock_wait_timeout is a year on mysql, LOCK_TIMEOUT is -1 on sql server and lock_timeout is 0 on postgres. So the open of a backend - and dsconfig create-backend-index on a running server - could queue behind an unrelated transaction of another session and never come back, and on postgres a queued CREATE INDEX parks every writer of that table behind its own lock request while it waits. A bound of the statement is the wrong tool for it, which is why the DDL stays StatementBound.BULK: a query timeout cannot tell a statement that is working from one that is queued, and only the second is worth ending. org.openidentityplatform.opendj.jdbc.ddl.lock.timeout (seconds, default 5, the bound the stamp of the same open already carries) is applied around the DDL alone - the create table and create index of openTree(), the drop table of deleteTree(), and the drop loop of removeStorageFiles() - and never as a session setting of the pooled connection: postgres and sql server bound every lock wait with it, row locks included, and write() replays no conflict of those. Per engine, in the unit its own setting takes: postgres gets "set local" (discarded by the commit that ends the DDL), mysql and sql server get theirs read back first and put back after, and oracle is left to its own ddl_lock_timeout, which gives up at once already. Nothing of ours is set where it could not be taken off a pooled connection again, and no statement of the bound is ever the failure of the DDL: a session that will not take it leaves the wait exactly as unbounded as it was before, reported once, and one that took the setting and then broke as the statement carrying it was closed has it taken off again before the DDL runs - a value left behind is on that connection for every borrower after it. A DDL that does give up at the bound is reported naming the property, the way timedOut() reports the bound of a statement, with the SQLState and vendor number carried over so that write() still classifies it as it did.
vharseko
left a comment
There was a problem hiding this comment.
Requesting changes on the first three; the rest are smaller and marked as such.
I read the description and #885 first, and where a code comment already states a trade-off deliberately — postgres, oracle, executeSessionStatement() staying outside the bound — I say so in the comment and only record what the stated reasoning does not cover. Nothing here asks for the session-wide placement the description rejects: that argument stands.
Worth changing
- A restore that fails leaves the bound on a pooled connection (1350). The javadoc's escape hatch — the next borrow validates and drops it — is a liveness check, so it does not fire.
- The two statements around the DDL carry no bound of their own in the one case where the DDL does carry one (
bulk.timeoutset), and the restore in thefinallycan hang the very open #877/#882 exist to unblock (1400, 1305). - On mysql the rewritten message can name a wait and a property that had nothing to do with the failure (1376).
Smaller
set localis a silent no-op without a transaction block (1036).- On postgres a failed
SETends as a failed backend open, not as "unbounded, as before" (1282) — recording the consequence; the trade-off itself is stated and I am not re-arguing it. - Three
IllegalStateExceptions reachable before the firsttry(1052). ddlLockBoundSeconds()duplicatesStatementBound.seconds()(945).- The property javadoc does not say oracle is exempt (940) — documentation only.
- An
Importerleft unclosed in the new test (JDBCDdlLockBoundTestCase:414).
Checked and not raising: the per-statement placement of the bound — the description quantifies the cost, and openTree() really is guarded by isExistsIndex() on all four dialects, so it stays the cold path; and sequential = true against the system property the class sets, since opendj-server-legacy/pom.xml runs surefire with <parallel>none</parallel>.
There was a problem hiding this comment.
Requesting changes. Checked against the head of this branch (11491f1), including the machinery this change leans on — CachedConnection's pooling and validation, timedOut()/Backstop, isConflict/isRetryableConflict/write(). Line numbers below are of the new file.
What stands — six comments
JDBCStorage.java:1272— on mysql and sql server the bound overwrites a deployment's own tighterlock_wait_timeout/LOCK_TIMEOUTinstead of taking the minimum, which is the argument used a few lines up to leave oracle alone. The displaced value is already in hand.JDBCStorage.java:1293— where theSETreached the server and onlyclose()failed, the DDL runs with the bound in force but outside thetrythat rewrites its failure, while the log says the wait was left unbounded.JDBCStorage.java:1357— the "left behind" warning re-readsddlLockBoundSeconds()at log time instead of naming the value actually stranded on the connection.JDBCStorage.java:436—ddlLockBoundLeftBehindWarnedis once per storage, so only the first poisoned pooled connection is ever reported.TestCase.java:192— nothing on a real engine asserts the restore, thoughsessionLockBound()is already there for it.TestCase.java:238— the oracle branch of the new container test passes for any failure that is not slow.
Withdrawn
This review crossed with review 5132390217 from the same account, submitted 70 seconds before it; when I checked this PR for existing rounds there were none. Five of my comments repeated points that review already makes, in places better. I have deleted them from the diff so nobody reads the same thing twice, and record here what they were and why they are retracted:
- the bound stranded on a pooled connection when the restore fails — already at 1350, which also names the
pool.destroy(this)path. - the rewrite naming a property that bounded nothing on a 1205 — already at 1376, with the same
ALGORITHM=COPYcase. lockNotAvailable()walkingWITH_THE_RELEASE— already at the end of that same 1376 comment, and framed better there:failureScope()uses the same walk deliberately, so it may be the intended convention, which mine did not allow for.- the three parallel switches and their
default: throw— already at 1052, which is also where I was wrong: those throws are reachable fromwithDdlLockBound()before anytry, not the dead code I called them. - scoping the bound per transaction rather than per statement — that review checked the per-statement placement and declined to raise it, having verified
openTree()is guarded byisExistsIndex()on all four dialects. I had not verified that; it stays the cold path and the point does not stand.
Nothing in that review is disputed here.
A connection whose reset failed no longer goes back into the pool. The validation of the next borrow is isValid(), a liveness check a connection carrying a stale lock_timeout passes, so leaving it to the pool to notice does not work: CachedConnection.poolable is no longer final and keepOutOfThePool() turns it off during the borrow, the way relaxReadBound() turns it off at establish time, and close() then destroys the connection instead of pooling it - with its permit. The round trips of the bound itself - the readback, the savepoint, the setting, the value given back - carry a bound of their own now (boundedSessionCall, SESSION_STATEMENT_BOUND_SECONDS): none of them takes a lock or reads a table, so a wait of one of them is a database that has stopped answering, and unbounded the restore parked the thread opening a backend from the finally of a DDL that had already failed. A failure is renamed only where this bound could still be what ended it, measured on the monotonic clock and allowed LOCK_BOUND_SLACK_MILLIS past the bound: mysql reports the row lock of innodb_lock_wait_timeout - 50 s by default, and what a create index under ALGORITHM=COPY waits on - as the same ERROR 1205 as a metadata lock, and naming this property for one of those sends an operator to raise the one setting that cannot help. The walk behind it drops the suppressed exceptions with it (WITHOUT_THE_RELEASE): this asks what the engine did with the statement, and the release runs after that outcome was decided. The bound never loosens a session that already gives up sooner. The displaced value is read before the bound SQL is built, and where the session is at least as tight nothing is set at all - no setting, no restore, and no rewrite of a failure this bound had no part in. In each engine's own encoding: mysql compares seconds, sql server milliseconds where -1 is "wait forever" and 0 "do not wait at all". That is the argument already leaving oracle alone, applied where the value costs nothing. On postgres the setting is taken back where it fails. A statement that fails inside a transaction aborts it, so the DDL after it failed with 25P02 rather than running unbounded as it did before this bound existed; a savepoint is taken first and rolled back to, which also undoes a set local that reached the server and failed only as its statement was closed. The DDL of that path now runs under the same rewrite as any other, since such a setting leaves it bounded after all. And SET LOCAL outside a transaction block is a warning the driver never raises, so getAutoCommit() is asked before issuing one rather than assumed. The three settings of a Dialect are abstract methods rather than switches with a default that throws: two of them are asked before the first try of withDdlLockBound(), where a constant added later without them would take out every DDL of the backend. StatementBound.seconds() and ddlLockBoundSeconds() read their property through one boundSeconds(). The warning about a bound left behind names the statement that set it rather than re-reading the property at log time, says the connection may carry it rather than that it does, and is throttled rather than said once for the life of the storage - each occurrence now costs the pool a connection. The property javadoc says oracle is exempt. Tests: a session already tighter, sql server's 0 and -1, auto-commit, the savepoint taken and rolled back, a lock wait far past the bound left as it is, a connection kept out of the pool, a socket read timeout armed around the session statements, and the importer of the clearTree case closed. On a real engine, the value a pooled connection carried is asserted back after a DDL - with postgres asserting the other shape of it, since a set local is gone only with the commit - and the drop that gave up is asserted by the engine's own verdict (lockNotAvailable) rather than by message text.
|
All fifteen taken, in Requested changes1. A failed reset strands the bound on a pooled connection (1350)The escape hatch was 2. The round trips of the bound carry no bound of their own (1400, 1305)Both cases hold; the reset in the 3. On MySQL the rewrite can name a wait and a property that had nothing to do with the failure (1376)Landed differently. The guard is there, but as an upper bound, because Smaller4.
|
vharseko
left a comment
There was a problem hiding this comment.
All fifteen are closed, and I checked each against the head rather than against the answer — including the
three that landed differently, which I go through below. The code is where I would approve it.
Requesting changes on one thing that is not the code.
Blocking
build.log is committed at the root of the repository
e325f6f4dc — the commit that answers this review — adds build.log: 3125 lines, about 196 KB of raw Maven
output.
I read it through. No credentials: every password hit is a test class name (PasswordModifyExtendedRequest TestCase, testAPasswordHoldingASlashPairIsNotLeftInTheLog). It does carry local paths, though —
/private/tmp/opendj-885-ddl and /Users/maximthomas/.m2 — and squash-merge puts them in the history of
master permanently, where a later removal does not reach them.
Nothing caught it because .gitignore has no rule for it: *.class, target/, hs_err_pid* and the IDE
entries, and nothing for *.log. So the fix is two lines — drop the file, and add the rule so the next one
does not arrive the same way.
That is the whole of the request. Everything below is either verified, a dismissal, or an answer to the
question you put to me.
The three that landed differently
Item 3 (1376) — the upper guard rather than timedOut()'s check. You are right that the check I pointed
at does not catch the case: timedOut() returns the failure untouched only while elapsed < bound - CLOCK_SLACK_MILLIS, and a 1205 arriving at 50 s clears that comfortably at a bound of 5 s. The inversion is
right for the reason you give — a lock timer fires at its own value, unlike a cancel a server is free to act
on late — and gaveUpOnTheLock (:1630) leaves the failure exactly as it arrived past
seconds*1000 + LOCK_BOUND_SLACK_MILLIS. The absence of a lower guard is argued in that method's javadoc, so
I am not re-opening it.
Item 10 (1272) — scoped narrower. I checked the part that decides whether the narrowing is safe: the early
return if (bound==null) { return action.run(); } (:1395) sits outside the try that calls
gaveUpOnTheLock, so a session that keeps its own tighter setting also keeps its own failure, unrenamed.
"No setting, no restore, and no rewrite of a failure this bound had no part in" is accurate as written. Reading
SQL Server's -1 as "wait forever" rather than as the tightest value there is is the part a plain min()
would have got wrong, and it is right here.
Item 11 (1418) — the restore moved into the finally. The catch reports, rolls the postgres transaction
back to the savepoint, and falls through into the same try that maps a failure through gaveUpOnTheLock, so
a DDL left bounded by a setting whose close() failed is now reported as the bounded one it is. The trade you
name — mysql and sql server running the DDL under a setting that may be in force rather than having it taken
off in front of it — is the right way round, since that setting is the thing this PR exists to put there.
I also checked the one way item 2's fix could have been undone by the machinery around it: boundedSessionCall
holds a backstop, and applyBackstop arms nothing while a statement of an unbounded class is in flight, so an
outer unbounded hold would have left the round trips unbounded after all. It cannot happen —
execute(statement, StatementBound.BULK) lives inside the action lambda at both call sites (:2704,
:2714), so the readback, the savepoint and the setting all run before the first unbounded hold is taken, and
the restore after it is released. And keepOutOfThePool() is the shape you describe: poolable is volatile
rather than final, turned off during the borrow, and close() takes the destroy path.
The question you put to me: postgres and the displaced value
Leave it. Do not pay the round trip there. set local exists precisely to avoid the readback; what is loosened
is loosened for the length of the DDL's own transaction and is gone with the commit that ends it; and the
asymmetry is stated at the constant, which is where the next reader looks. One method's worth of code is not
the cost — the round trip on every DDL of a backend opening its trees is, and it buys a rule that has almost
nothing to bite on there.
CodeQL 1283 is a false positive, and worth dismissing as one
JDBCStorage.java:1541, raised on this round's code: "Missing catch of NumberFormatException" on
Long.valueOf(rows.getString(1).trim()).
It is caught. That call runs inside the lambda handed to boundedSessionCall, and the call site one line below
is catch (SQLException | RuntimeException e) with the comment saying so outright — "a value that is not a
number arrives unchecked". The rule looks for a catch naming NumberFormatException or
IllegalArgumentException and does not credit a broad RuntimeException. Worth closing the alert with that
reason rather than leaving it open on the repository after the merge.
Two things I checked and am not raising. The description is genuinely rewritten for this round rather than
patched — keepOutOfThePool, boundedSessionCall, the savepoint, boundSeconds, the already-tighter rule,
the abstract Dialect methods, the upper guard and the 36 cases are all in it — which is not something I could
say of the other three branches this week. And JDBCDdlLockBoundTestCase.java carries the standalone
Copyright 2026 3A Systems, LLC. a new file takes.
Reviewed against pull/936/head (e325f6f4dc). CI I cannot report on: at the time of writing almost every job
of that head is still pending — the build-maven matrix, wait-msi-artifact and the Analyze jobs — with no
failure among the ones that have finished. No database here either; the dialect behaviour is read off the code
and the engine defaults, not exercised.
…ew answer e325f6f carried build.log into the root of the repository: 3125 lines of raw Maven output, about 196 KB, and with the local paths of the machine that produced it - /private/tmp/opendj-885-ddl and /Users/maximthomas - in it. It is not part of this change and was never meant to be in the tree. Nothing stopped it because .gitignore has no rule for a log: *.class, target/ and hs_err_pid* are there, and no *.log. The rule goes in with the Maven ignores, which is where the output of a build belongs, so a build redirected to a file is not offered up for staging again.
|
Requested change1.
|
vharseko
left a comment
There was a problem hiding this comment.
Approving. build.log is out and the rule that should have kept it out is in, which was the whole of the request — the code itself was already where I would approve it last round.
The removal, checked against the tree rather than taken on the word of it
118c8e86 drops the file and puts *.log in the Maven section of .gitignore, next to target/. Confirmed here: nothing matching is tracked on this branch or on master, so the rule takes nothing else out; there is no negation in .gitignore for it to collide with; and the branch is three commits on 995d54a8 with nothing unrelated carried in.
Your correction on the risk stands and mine does not. A squash takes the diff of this branch's tree against master, so a removal made here does reach it and no merged commit would have carried the file either way. What the removal cannot reach is e325f6f4dc behind refs/pull/936/head — which is reason enough on its own, and is the reason I should have given.
CodeQL 1283 is dismissed as a false positive, so nothing of this round is left open on the repository after the merge.
I read the head again rather than only this commit: the headers, the state and vendor number the rewrite carries over, the permit accounting behind keepOutOfThePool() (poolable is read in one place, and its false branch is the pool.destroy(this) that gives the permit back), and the invariants #866, #877 and #882 wrote down — the innodb_lock_wait_timeout this does not touch among them. Nothing moved that should not have.
Recorded for a follow-up, and not a condition of this approval
withDdlLockBound() returns early and says nothing where the dialect is unknown:
dialectOf() keys on the driver class name, so MariaDB Connector/J — or a Percona- or Aurora-branded driver — against a live MySQL answers null. That is a session whose lock_wait_timeout is a year, which is the wait this PR exists to end, and a deployment that set ddl.lock.timeout there is told nothing about it: reportTheWaitIsLeftUnbounded fires on a SQL failure and never on this return, and the property javadoc names the oracle exemption alone.
This is item 5 of my review of #934, one property later — "Being conservative there is defensible … but the silence is not, given that the strict parsing of the value exists so that a deployment that asked for a bound and misspelled it is not left with none quietly." reportUnknownDialect closed it there, but it speaks of the connect bound and pool.timeout and keys off the url rather than the driver, so it does not reach this bound. The conservative behaviour is right and testAnEngineThisBackendDoesNotKnowIsLeftAlone pins it deliberately; it is only the silence that is worth a line, here or in a follow-up of its own.
CI I cannot report on yet: most of the matrix is still pending on this head, with no failure among the jobs that have finished.
…-lock-bound Two conflicts were reported and a third was not. In TestCase.java it is adjacency alone: both sides added a container case below testLoginBoundDoesNotOutliveTheLogin, and both are kept. The javadoc opener the two were fighting over belongs to master's - "And the bound that replaces it reaches the socket of the driver" continues the case above it - so that one stays where it was and the two lock-bound cases follow with an opener of their own. The first conflict in JDBCStorage.java is adjacency too: a warn-once latch each, below queryTimeoutWarned. The second is a real one. OpenIdentityPlatform#893 rewrote removeStorageFiles() to drop what the tree catalog names rather than what listTrees() does, counting as it goes and reporting what it left standing, while this branch had replaced its drop loop with a dropTables() that puts one lock bound around the whole of it. Master's loop is kept exactly as it stands - the same skip, the same three counts, the same order - and moved into dropCatalogTables(), which runs it under a single withDdlLockBound() and hands the counts back in a ClearCounts. The loop is deliberately not split into "name every table, then drop them all": the skip in it decides between leaving a row where it is and dropping the table it names, and it must go on being answered by a database that has already seen this loop's earlier drops. A clear with no row to act on is committed without the bound. Putting it on costs a readback and a restore, and the case CLEAR_DROPPED_NOTHING describes - the first clear of a backend upgraded from a version that kept no catalog - has no DDL for them to bound; before this merge that path issued the drops and nothing else. The conflict git did not report is in JDBCDdlLockBoundTestCase. OpenIdentityPlatform#893 made deleteTree() ask its catalog first, which reads the backend id off the configuration and wants a connection this class's mock does not hand out, so testTheDropOfATreeIsBounded failed with an NPE on a mockCfg that answers null. The storage of a case is now configured with a backend id, and its connection answers that the catalog table is not there - the backend upgraded from a version that kept none, which is the shortest way to the funnel these cases are about; CatalogConnectionTestCase covers the catalog itself. The same case now expects the "select unnest(current_schemas(true))" of TableScope in front of the drop: it is the lookup deciding whether there is a table to drop at all.
vharseko
left a comment
There was a problem hiding this comment.
Code review
The merge only (6752ecc3e8). The approval of 118c8e86b7 stands and nothing below is a condition of it.
Checked first that the resolution is what the commit message says it is, and it is. Master's drop loop is transplanted verbatim into dropCatalogTables() — same skip, same three counts, same order (catalogTables() still puts the catalog last), same single commit, same rollback at the removeStorageFiles() level; the empty-catalog early return commits exactly where master's zero-iteration loop did. TestCase.java is adjacency alone, and the two container cases are no more order-dependent than before: testTheStandingReadBoundReachesTheSocket restores readTimeoutMillis and drains the pool on the way out. CachedConnection.java merged with no conflict reported and none hidden either: poolable still has exactly one reader (close(), choosing pool.destroy(this)) and one writer added by this branch, #934 adds neither, and each boundedSessionCall() takes a fresh Backstop, so state.previous is never read under a lift and nothing of #934's standing read bound is left off. .gitignore, the five license headers and the five-file footprint all survive — git diff 2a7bb9d7ed 6752ecc3e8 reverts nothing master shipped, and no .log came back with the merge.
Two things did not survive it.
Found 2 issues:
- The loop's own lookup is now inside the bound but outside the rewrite, so a lock this bound ends is reported as the bare vendor error.
dropCatalogTables()puts master's whole loop underwithDdlLockBound(), and that loop callsisExistsTable()once per row — a statement neither parent ran inside the bound: master had no bound at all, and the branch'sdropTables()ran only thedrop tablestatements.isExistsTable()turns every failure into aStorageRuntimeException, andwithDdlLockBound()renames only what arrives as aSQLException, so a55P03/1205/1222that the lookup gave up with never reachesgaveUpOnTheLock(). The asymmetry is inside one iteration: the drop is renamed and names the property, the lookup deciding whether to issue that drop is not, and an operator meets exactly the unexplained state this PR exists to stop shipping.
dropTable()'s javadoc was left behind by the resolution.ClearCountsanddropCatalogTables()were inserted between the comment and the method it documents, so the block now stands in front ofClearCounts— "Drops one table of a clear. It is a method of its own", of a counts holder, followed immediately by that class's own one-line javadoc — whiledropTable()60 lines below carries none. It is the copy of the ordering reasoning that sat at the drop itself;catalogTables()still states the ordering, so nothing is lost outright, but the comment now describes neither the class it precedes nor the loop that moved.
Checked and not raising. The bound sitting around the whole loop rather than around each drop, and what that does to gaveUpOnTheLock()'s slack window once the loop's earlier drops are work of their own: that shape is the branch's own, it is argued at LOCK_BOUND_SLACK_MILLIS and it was approved last round — the merge only enlarged what runs inside a lambda that already had it. The unknown-dialect silence recorded last round is untouched and still a follow-up. Both new cases earn their place: testAClearWithNoTableToDropIsGivenNoBound fails with the early return deleted (the set local is issued into an empty loop), and testTheDropLoopOfARemovedBackendIsBoundedOnce fails on the exact-list equality if the bound moves per drop, so "once" is really pinned and not just "a bound appears".
CI I cannot report on: every job of this head — the build-maven matrix, wait-msi-artifact and the four Analyze jobs — is still pending, with no failure among them. No database here either; the dialect behaviour above is read off the code and the engine defaults rather than exercised.
vharseko
left a comment
There was a problem hiding this comment.
Requesting changes on the two findings of my review of this merge a few minutes ago, which supersedes the approval of 118c8e86b7 until they are answered. The reasoning, the links and what I checked and am not raising are all there and are not repeated here — this only changes the state of the round, and nothing new was found since.
Both are of the merge (6752ecc3e8) and of nothing that was approved last round:
-
isExistsTable()is inside the bound and outside the rewrite (JDBCStorage.java:2841).dropCatalogTables()runs master's whole loop underwithDdlLockBound(), and that loop's lookup wraps every failure in aStorageRuntimeException, whichcatch (SQLException e) { throw gaveUpOnTheLock(...) }(:2118) cannot see. A55P03/1205/1222the lookup gave up with therefore reaches an operator bare, in the same iteration whose drop would have named the property. Neither parent ran a statement of that kind inside the bound, so this arrived with the resolution. -
dropTable()'s javadoc was left behind (JDBCStorage.java:2791-2797).ClearCountsanddropCatalogTables()went in between the comment and its method; the block now introduces a counts holder as "a method of its own", anddropTable()(:2861) has no javadoc at all.
The second is a line to move. For the first, whatever closes it is fine by me — the lookup answering with the SQLException it was given, the rewrite reaching an unchecked failure the way removeStorageFiles()'s own catch (Exception e) already has to, or the lookup taken back out of the bound — as long as a lock this bound ended does not come out of that loop unnamed. If you conclude it should stay as it is, say why and I will take it.
…-lock-bound Two conflicts, one of them silent. The reported one is an import: master added java.util.concurrent.atomic.AtomicInteger next to the AtomicLong this branch added, and both are kept. The silent one is OpenIdentityPlatform#904 (a1b8537's neighbour 9a086de), which replaced JDBCStorage.isRetryableConflict(Throwable, String) with conflictVerdict(Throwable, String) returning a ConflictVerdict. The two JDBCDdlLockBoundTestCase cases that check a failure rewritten by the bound is still classified the way it was before it existed now read the class off that verdict: Conflict.AFTER_LOCK_WAIT for the MySQL 1205 under 40001, which is what the new enum calls the conflict an engine reports only after a lock wait timeout of its own, and Conflict.NONE for the SQL Server 1222, which is no conflict a write() replays. Both assert the class rather than a boolean, so the vendor number the bound carries over is what they turn on. The import connections of OpenIdentityPlatform#891 (a1b8537) do not meet this bound: an Importer issues clearTree, put, read and openCursor, and every DDL of this backend is in WriteableTransactionImpl.openTree/deleteTree, dropCatalogTables and createCatalogTable. Verified: JDBCDdlLockBoundTestCase 37, CachedConnectionTestCase 100, JDBCStorageRetryTest 99, JDBCStatementBoundTestCase 44, ImportConnectionsTestCase 18, CatalogConnectionTestCase 13, StampConnectionTestCase 5 - 316 run, 0 failures, 0 skipped. No Docker on this machine, so the four container suites confirm nothing about the engines.
…clear gave up on The drop loop of removeStorageFiles() runs under a single lock bound, and the lookup deciding each drop runs inside it. That lookup wraps whatever it sees in a StorageRuntimeException, which the rename of withDdlLockBound() - a catch of SQLException alone - could not see: a 55P03 / 1205 / 1222 the lookup gave up with reached an operator bare, in the same iteration whose drop would have named the property. The rename now reaches an unchecked failure too, reading its chain for the engine's own way of saying the lock was not available and putting that link through the same slack window. A failure the rename does not apply to is given back exactly as it arrived. Also moves the javadoc of dropTable() back to it: the merge resolution inserted ClearCounts and dropCatalogTables() between the comment and the method it documents.
|
Both closed in 1. The lookup inside the bound and outside the rewriteConfirmed as described: Of the three closures you offered I took the second, the rewrite reaching an unchecked failure: }catch (RuntimeException e) {
throw gaveUpOnTheLock(e, dialect, seconds, startedAt);
}with an overload that reads the chain for the engine's own way of saying the lock was not available — Why not the other two:
The catch covers any future statement placed under a bound too, which is the shape the finding is really about. 2.
|
vharseko
left a comment
There was a problem hiding this comment.
Approving. Both findings of my review of the merge 6752ecc3e8 are closed, and I checked each against the head rather than against the answer.
What this round contains
Your comment puts 9cc5a0efa0 "on top of the merge you reviewed". It sits on top of a second one - 69afe2d552, seventeen minutes earlier - which is also new since the last round and brings #891, #904, #901, #908 and #916 into the branch. Its own commit message says exactly what it resolved, so nothing was hidden; the comment just does not name it, and a reader of the comment alone would take this round for one commit. I reviewed both.
The merge
I reconstructed git's own auto-merge of 6752ecc3e8 with 5d176c6915 and diffed the committed tree against it. The whole hand resolution is the two things the commit message names and nothing else: master's AtomicInteger import kept beside this branch's AtomicLong, and the two cases holding a failure the bound renamed to the classification it had before the bound existed, moved from isRetryableConflict(...) to conflictVerdict(...).conflict. No third edit, and nothing of either side dropped.
Those two assertions are faithful and not merely green: on the pre-merge code MySQL 40001/1205 was isConflict -> true and SQL Server S0001/1222 -> false, which is what Conflict.AFTER_LOCK_WAIT and Conflict.NONE say under the new enum, and no call to isRetryableConflict survives anywhere in the tree.
What git resolves silently is where a merge this size actually goes wrong, so: master adds no DDL statement site; execute, bounded, boundedSessionCall, Backstop and applyBackstop are untouched by it; and it changes neither poolable nor keepOutOfThePool() - its only CachedConnection changes are isUnboundedWait()/boundedWait() and getNonNegativeProperty going package-private for #891. An import connection of #891 is borrowed from the same pool with the same setAutoCommit(false), so it meets this bound on the same terms as any other connection and inATransactionBlock() reads it the same way.
One warning for whoever reads this merge after me: git diff 6752ecc3e8 5d176c6915 is not the diff to read. 6752ecc3e8 is not on master's line - the base is 2a7bb9d7ed - and that naive pairing makes it look as though master had deleted keepOutOfThePool() and made poolable final. It did neither.
1. The lookup inside the bound and outside the rewrite - closed
Of the three closures I offered you took the second, and it is the one I would have taken: the other two are the signature change and the loop regression you describe, and both cost more than the finding.
The rename reaches an unchecked failure through the same classifier and the same slack window as the checked one - firstLinkMatching(..., WITHOUT_THE_RELEASE, EVERY_LINK, isLockTimeout), then the existing gaveUpOnTheLock(SQLException, ...) - so nothing new decides what counts as a lock this bound ended.
The parts that could have gone wrong quietly:
- Nothing is swallowed.
link==nullandrenamed==linkboth give the original object back by reference, so a failure that was no lock wait - and one that arrived far past the bound - leaves this method exactly as it entered it. Therenamed==linktest is sound because the checked overload has no third outcome: it returns its own parameter or a new object. - The classification is preserved. The rename is built from
linkrather than from the wrapper, so the state and the vendor number are the ones a caller read before;removeStorageFiles()'se instanceof StorageRuntimeExceptionstill holds, and its rollback still runs. - The other call site stays inert. Everything in
commitStatement()'s lambda isthrows SQLException, so the new catch has nothing to take there - which is what makes this a change to the clear path and to nothing else. EVERY_LINKis no new risk.walkLinks()terminates on its identity set whatever the budget, and this is the budgetlockNotAvailable()has used since the round that added it.
Both new cases earn their place, and each kills its own mutant and only its own, as you say. The assertSame in both is a real pin rather than an accident: givingUpOnTheLookup() re-stubs getMetaData() after TableScope.of() has used the original, and the mock's elapsed time is nowhere near the slack window.
2. dropTable()'s javadoc - closed
Back in front of the method, and the {@link} now names dropCatalogTables(), which is where the loop it is about lives. The insertion-order guarantee the block asserts still holds - readCatalogRows builds a LinkedHashMap. ClearCounts reads correctly with its own one-line javadoc.
Recorded, and not a condition of this approval
The description no longer describes the code. It was rewritten for e325f6f4dc and has not moved since, which is two rounds: it says JDBCDdlLockBoundTestCase, 36 cases and 230 tests where your own last comment says 39 and 318; it names "the drop table loop of removeStorageFiles()" as the second call site, which the merge moved into dropCatalogTables(); and it presents the rewrite as the one around the DDL, with no mention of the lookup or of the unchecked path this round added. Nothing in it is wrong about the design and the commit messages carry the rest - but it is the document a reader meets first, and last round I said of it that it was genuinely rewritten rather than patched, which I could not say of it now.
The unknown-dialect silence recorded two rounds ago is untouched and still a follow-up.
CI I cannot report on: every job of 9cc5a0efa0 - the build-maven matrix, wait-msi-artifact and the four Analyze jobs - is still pending, with no failure among them. No database here either, so the dialect behaviour above is read off the code and the engine defaults rather than exercised.
Part of #885 — its section 1. The read bound of section 2 is a PR of its own; nothing here depends on it.
Problem
The DDL of the JDBC backend is the one part of it that takes locks, and three engines out of four wait for one essentially forever:
lock_wait_timeoutis a year on MySQL,LOCK_TIMEOUTis -1 on SQL Server,lock_timeoutis 0 on PostgreSQL. Only Oracle'sddl_lock_timeoutgives up at once, and it defaults to 0 — give up immediately.So a
create table, acreate indexor adrop tablethat arrives while an unrelated transaction of another session holds the table can queue behind it and never come back. What that hangs is not a background job:openTree()creates a table and three indexes per tree, andRootContainer.open()opens every tree of every base DN;dsconfig create-backend-indexon a running server, which opens a tree on a live instance;CREATE INDEXparks every writer of that table behind its own lock request while it waits, so one blocked DDL becomes a stalled backend.#882 bounded every statement of this backend by the class of the work it belongs to, and deliberately left the bulk class — which the DDL belongs to — unbounded. That decision stands and is the reason this PR exists: a query timeout cannot tell a statement that is working from one that is queued. A
create indexon a populated table legitimately takes as long as it takes; acreate indexwaiting for a metadata lock has done nothing at all. Only the second is worth ending, and only a lock bound can name it.Change
org.openidentityplatform.opendj.jdbc.ddl.lock.timeout, in seconds. The default is 5, which isCOMMENT_LOCK_TIMEOUT_SECONDS— the bound the table stamp of #866 already carries while taking its lock on the very tables this DDL creates and drops.0or negative leaves the wait exactly as unbounded as it was before; a value that is not a number keeps the default, asInteger.getInteger()has it, so a typo cannot silently unbound it; a value pastMAX_BOUND_SECONDSis clamped down through the existingclampSeconds(). Every bound of this backend reads its property through oneboundSeconds(), so a later change to how these are read cannot leave this one behaving unlike the rest.The bound is applied around the DDL, never as a session setting of the pooled connection. This is the placement the issue asks about, and the alternative has a hazard worth stating: PostgreSQL's
lock_timeoutand SQL Server'sLOCK_TIMEOUTbound every lock wait, row locks included, andisConflict()classifies neither55P03nor error 1222 as a replayable conflict. A session-wide setting would therefore turn ordinary row contention into client-visible failures where today the write waits and succeeds. Scoping it to the DDL avoids that entirely.Per engine, in the unit its own setting takes:
set local lock_timeout = <ms>set localends with the transaction the DDL commitsselect @@session.lock_wait_timeoutset session lock_wait_timeout = <s>select @@lock_timeoutset lock_timeout <ms>Each of those constants answers those three settings itself — they are abstract methods of
Dialect, not a switch with adefault: throw— because two of them are asked before the firsttryofwithDdlLockBound(): a constant added later without them would take out every DDL of the backend on the one path whose contract is that no statement of the bound is ever the failure of a DDL.The bound never loosens a session that already gives up sooner. The displaced value is read before the bound is built, and where the session is at least as tight as this property nothing is set at all — no setting, no reset, and no rewrite of a failure this bound had no part in. That is the same argument that leaves Oracle alone, applied where the value costs nothing to respect. In each engine's own encoding: MySQL compares seconds (
lock_wait_timeouthas no value meaning "wait forever" — its range starts at 1); SQL Server compares milliseconds, where-1is "wait forever" and is replaced, while0is "do not wait at all" and is kept, so a plainmin()would have read the loosest value there is as the tightest. PostgreSQL is the one place this does not reach: the value is not in hand there, and reading it back is the round trip aset localexists to save — and what is loosened there is loosened for the length of the DDL's own transaction and no longer.MySQL gets
lock_wait_timeoutand neverinnodb_lock_wait_timeout. The first is the metadata lock a DDL takes; the second is the row lock, already 50 s by default, and it is whatwrite()'s conflict replay depends on. The issue names both; only the first belongs here.Oracle is left alone deliberately. Its
ddl_lock_timeoutdefaults to 0, which is already tighter than anything this would set — applying ours would loosen it — and a deployment that raised it globally did so on purpose. Putting it back would also mean readingv$parameter, a privilege the account of a backend often does not have. The javadoc of the property says so, since that is what an operator reads after an ORA-00054.The set, the readback and the reset go through the existing
executeSessionStatement(), which already documents why a session setting has to reach the server as a plain batch rather than throughprepareStatement: the SQL Server driver runs a prepared statement throughsp_executesql, and a setting made there is reverted when that call returns — before the statement it is meant to protect ever runs. Every round trip of the bound itself carries a bound of its own, though: the readback, the savepoint, the setting and the reset run underboundedSessionCall(), which holds the socket read timeout for the length of the call. None of them takes a lock or reads a table, so a wait of one of them is a database that has stopped answering rather than work in progress — and unbounded, the reset parked the thread opening a backend from thefinallyof a DDL that had already failed, which is the hang #877 and #882 exist to end. The DDL between them keeps its own class, which ships unbounded.Two call sites, both through one helper (
withDdlLockBound):commitStatement(sql, ddl)whenddl == true— the funnel every DDL of a transaction goes through: thecreate tableand threecreate indexofopenTree(), and thedrop tableofdeleteTree(). The importer reaches the same funnel.ddl == false—clearTree()'sdelete from— is left alone, waiting for its row locks as it does now;drop tableloop ofremoveStorageFiles(), which bypasses that funnel and commits once at the end, so the bound is set once around the whole loop. On PostgreSQL oneset localcovers every drop of that single transaction.No statement of the bound is ever the failure of a DDL. A backend that opened before this bound existed has to open still, so every way the bound can go wrong degrades to "the DDL runs anyway", reported once:
SETof it would take back, is given no bound at all — nothing is ever set that could not be taken off again;set local: outside a transaction block PostgreSQL answers that with a warning no driver raises, so the DDL would run with no bound and the log would read exactly like a bounded one.getAutoCommit()is asked rather than assumed, and costs no round trip;JDBCStorageRetryTestalready drives, and the first revision of this change failed that suite). On PostgreSQL the transaction is taken back to a savepoint taken in front of the setting — a statement that fails inside a transaction there aborts it, and the DDL would otherwise fail with25P02rather than running unbounded;close()of the statement carrying it has left the DDL bounded after all, and no driver says which of the two happened. So the DDL of that path runs under the same rewrite as any other, the reset still gives the value back after it, and on PostgreSQL the rollback to that savepoint undoes theset localas well — which is why the warning says the wait may be unbounded rather than that it is;finallywhile the caller may be being unwound, where a throw takes the place of whatever brought it there (JLS 14.20.2). The connection it failed on is kept out of the pool (CachedConnection.keepOutOfThePool()), because the validation of the next borrow isisValid()— a liveness check a connection carrying a stale setting passes, after which SQL Server would cut every lock wait of that borrower at our bound, row locks included. The report names the statement that was issued rather than re-reading the property at log time, and is throttled rather than said once for the life of the storage: each occurrence now costs the pool a connection.A DDL that does give up at the bound is reported as what it is. It arrives as a bare
55P03/ERROR 1205/error 1222, naming neither the wait it ended nor the property that ended it — the same gaptimedOut()closes for the bound of a statement. The rewrite names the property and says raising it, or setting it to 0, is the remedy.Three details of that rewrite matter more than the message:
timedOut()measures its own, and a wait that ran more thanLOCK_BOUND_SLACK_MILLISpast the bound is left exactly as the engine reported it. More than one wait of an engine reports the same number: MySQL reports the row lock ofinnodb_lock_wait_timeout— 50 s by default, and what acreate indexunderALGORITHM=COPYwaits on — as the same ERROR 1205 as a metadata lock, and naming this property for one of those sends an operator to raise the one setting that cannot help. There is no guard under the bound to go with it: the states matched here are what an engine says when a lock wait ran out, and nothing this backend issues says them otherwise;isLockTimeout()is extracted out ofscopeOf(), which is behaviour-preserving forfailureScope(). It is asked directly rather than throughfailureScope(), which also reads anySQLTimeoutExceptionas a moment — a statement its own class bound cancelled is one of those, andtimedOut()has already named the property that ended it. The chain is walkedWITHOUT_THE_RELEASE, as that constant documents: this asks what the engine did with the statement, and the release of the connection runs after that outcome was decided, so a55P03out of the rollback that gave the connection back cannot rename a DDL that failed for something else;write()knows; PostgreSQL55P03and SQL Server 1222 stay the non-conflicts they were. No failure becomes replayable, and none stops being.Nor can a bounded DDL be replayed into a fresh wait each attempt:
commitsBeforeDdl()is true on MySQL and Oracle, sopartlyCommittedis raised before the DDL is issued and takes it out ofwrite()'s replay; PostgreSQL and SQL Server report states that are no conflict.What it costs is the round trips around each DDL — three on MySQL and SQL Server (read the value back, set the bound, give the value back), two on PostgreSQL (the savepoint and the setting), none on Oracle — and only on the cold path. An existing backend issues no DDL at all: every statement of
openTree()is guarded by a catalog read. A session already tighter than the bound pays none of them past the readback.Out of scope
55P03/ 1222 replayable conflicts. That is only needed by the session-wide placement this PR rejects, and it would changewrite()semantics for row contention nobody asked about.ddl_lock_timeout, for the reason above.lock_timeoutback so the bound cannot loosen it there, for the reason above — one round trip, one method, if it is wanted.bulk.timeout, which [#877] Bound a statement of the JDBC backend by the class of the work it belongs to #882 shipped deliberately.Testing
JDBCDdlLockBoundTestCase, 36 cases, no database needed: the SQL each of the four dialects is told around a DDL and in what order, the default and every misconfiguration of the property, a session already tighter than the bound (and SQL Server's0against its-1), a connection in auto-commit, the savepoint taken and rolled back, the reset that happens even when the DDL throws, PostgreSQL issuing no reset, the connection kept out of the pool when the reset fails, the socket read timeout armed around the session statements, a lock wait far past the bound left as it is,clearTree()being left alone (driven through the realImporterImpl), the drop of a tree and the drop loop of a removed backend, and each way the bound degrades instead of failing the DDL.JDBCDdlLockBoundTestCase36,CachedConnectionTestCase86,JDBCStatementBoundTestCase37,JDBCStorageRetryTest66,StampConnectionTestCase5 — 230 tests, 0 failures, 0 errors, 0 skips.Passing is not on its own enough, so the guards were built with their defect put back:
testAConnectionWhoseBoundCouldNotBeTakenOffIsKeptOutOfThePoolfails,expected [true] but found [false]testALockWaitFarPastTheBoundIsLeftExactlyAsItIsfails: a 1205 that arrived after 50 s comes back named asthe 5s of ...ddl.lock.timeouttestAConnectionInAutoCommitIsGivenNoSetLocalfails,lists don't have the same size expected [1] but found [2]— theset localissuedtestTheTransactionIsTakenBackToBeforeASettingThatFailedfails,Wanted but not invoked: connection.rollback(savepoint)testTheRoundTripsOfTheBoundCarryOneOfTheirOwnfails,armed no socket read timeout: []testAMysqlSessionAlreadyTighterThanTheBoundKeepsWhatItHasfails,expected [2] but found [4]-1as the tightest value there istestWhatEachEngineIsToldAroundADdlfails for that engine,expected [4] but found [2], andtestARewrittenSqlServerLockWaitIsMadeNoMoreReplayablewith ittestADdlBoundedByASettingWhoseCloseFailedStillNamesThePropertyfails: the failure keeps its bare 1205SETwhich failedtestASettingThatBrokeOnTheCloseOfItsStatementIsStillTakenOfffails — the value never given backcatchofrestoreDdlLockBound()allowed to throw...ValueThatCouldNotBeGivenBack...cases fail, the restore's ownSQLExceptiontaking the place of the DDL's outcometestALockTheDdlGaveUpOnNamesTheProperty(expected [55P03] but found [null]),testARewrittenMysqlLockWaitStaysTheConflictAWriteKnowsandtestARewrittenSqlServerLockWaitIsMadeNoMoreReplayable(expected [1205] but found [0],expected [1222] but found [0])Under a real lock:
testTheDdlGivesUpOnALockAnotherSessionHoldsinjdbc/TestCase, inherited byPgSqlTestCase,MySqlTestCase,MsSqlTestCaseandOracleTestCase. It sets the property to 2 s, opens a tree, holds an uncommittedinserton it from a second rawDriverManagersession — the lock every engine conflicts adrop tablewith — and assertsdeleteTree()fails rather than hanging. The failure is asserted by the engine's own verdict (lockNotAvailable(): ORA-00054 /55P03/ 1205 / 1222) before the property name is looked for, so a drop that failed because the table was not there or because a privilege was missing no longer passes it — on Oracle above all, where nothing of ours is set and only the absence of our property name was being checked.@Test(timeOut = 120000), so a regression is a failure rather than a hung suite.The other half of that contract on a real engine:
testAConnectionGetsItsLockBoundBackAfterADdlborrows throughCachedConnection.getConnection(), reads what the session carries, runs a DDL that reads it again from inside the bound, and reads it a third time afterwards — so the value a pooled connection is left with is asserted by the engine rather than by the string handed to a mock. PostgreSQL asserts the other shape of it, which a single "it is back" assertion would have got wrong there: theset localis still in force whenwithDdlLockBound()returns and is gone only after the commit that ends the transaction.