[#885] Bound the create of the tree catalog, and say when an engine has no bound to give - #1003
Open
vharseko wants to merge 5 commits into
Open
[#885] Bound the create of the tree catalog, and say when an engine has no bound to give#1003vharseko wants to merge 5 commits into
vharseko wants to merge 5 commits into
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.
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.
…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.
…-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.
…say when an engine has no bound to give The create table of the tree catalog is the DDL of this backend that reaches neither commitStatement() nor the drop loop: openTree() issues it on the catalog's own connection before it enrols the tree it is opening, so the bound of this branch never covered it. It is BULK, so it carries no query timeout, and the standing read bound of OpenIdentityPlatform#934 is lifted for the length of an unbounded statement - which left it the one statement of this backend with no bound of any kind, on the open path, inside the monitor every other thread of the storage queues on. It now runs under withDdlLockBound() like every other DDL, with the commit inside the bound: on postgres that commit is what ends the transaction a "set local" belongs to. That connection is not the pool's, so the two places claiming a connection reaching this code is pooled say what happens to the catalog's own instead - it is closed with the write that opened it. And an engine behind a driver this backend knows no lock setting for is now reported once rather than left silent. dialectOf() keys on the class name of the driver, so a mariadb, percona or aurora driver against a live mysql answers null - a session whose lock_wait_timeout is a year, which is the wait this bound exists to end. Leaving the bound off there stays; only the silence goes, for the reason the strict parsing of the property exists. CachedConnection cannot say it: it keys on the url, which such a driver reads as a mysql one. JDBCDdlLockBoundTestCase gains six cases: what postgres and mysql are told around the create of the catalog table, the lock it gives up on naming the property out to the operator, and the three placements of the report - the unknown engine, the bound nobody asked for, and the oracle left alone on purpose. The suite is mock-only and now stays that way: the storage of a case answers newStampConnection() itself rather than letting it reach DriverManager.
vharseko
added
bug
jdbc
tests
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
2 participants
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
Part of #885, and it sits on top of #936:
withDdlLockBound()is that branch's code. Until #936 merges, the diff of this PR carries its four commits as well - the one commit to read here is1c40760, two files. Rebasing onto master and cutting the diff down to that commit is a force-push away once #936 is in.Problem
#936 bounded the DDL of this backend by putting
withDdlLockBound()on the two paths its DDL goes through -commitStatement(sql, ddl==true)and the drop loop of a removed backend. There is a third, and it is neither of them.createCatalogTable()issues itscreate tableon the catalog's own connection, beforeopenTree()enrols the tree it is opening. That statement:StatementBound.BULK, so it carries no query timeout by design ([#877] Bound a statement of the JDBC backend by the class of the work it belongs to #882);So after #934 and #936 it is the one statement of this backend with no bound of any kind. Where it runs makes that worse rather than better: it is on the open path, and it runs inside
synchronized (catalogLock)- a wait there parks every other thread of the storage that wants the catalog, not only the one that queued.Nor does that wait need an exotic database. The method's own comment names the case: "a table that turned up between the lookup and this statement is what was wanted, whoever made it" - an offline tool beside a running server, the pair #888 is about. On postgres a second session creating that same table inside a transaction it has not committed makes this one wait on that transaction,
lock_timeoutbeing 0 by default; a lock held on the schema does the same.It arrived after both were written:
createCatalogTable()came with #893, which merged the same morning #934 did, and #936 took it in through its merge of master without the bound reaching it.Change
1. The create of the catalog table runs under
withDdlLockBound(), like every other DDL of this backend. The commit is inside the bound, because on postgres it is that commit which ends the transaction aset localbelongs to.Everything the bound leans on already works on this connection:
physical()passes a raw connection through,dialectOf()reads the driver name off it, andrestoreDdlLockBound()already asksinstanceof CachedConnectionbefore keeping a connection out of a pool. What did not fit is what two comments claim, this being the one connection reaching that code which was never in the pool: the javadoc ofwithDdlLockBound()and the "left behind" warning ofrestoreDdlLockBound()now say what becomes of the catalog's own - it is closed with the write that opened it, so a setting left on it reaches the rest of that write and nothing after it.A lock this create gives up on reaches the operator named:
gaveUpOnTheLock()rewrites it, the existingcatchcarries it into theStorageRuntimeExceptionsaying which table the backend wanted and why, and the property is in that chain. Unbounded, it arrived as a bare55P03inside a message about privileges - which is the wrong thing to go and check.2. An engine this backend knows no lock setting for is reported, once. The early return of
withDdlLockBound()had three reasons behind one condition; they are three conditions now, and only the middle one speaks:seconds<=0- the deployment asked for no bound, and there is nothing to say;dialect==null- reported, naming the class of the driver;ddlLockBoundSql(seconds,null)==null- oracle, left alone deliberately and documented as such.dialectOf()keys on the driver class name, so this is not the engine of an exotic database alone: MariaDB Connector/J - or a Percona- or Aurora-branded driver - against a live MySQL answers null here, and that is a session whoselock_wait_timeoutis a year, which is the wait this bound exists to end. Leaving the bound off there stays, andtestAnEngineThisBackendDoesNotKnowIsLeftAlonestill pins it: untested SQL is no thing to send a database on the path a backend opens by. Only the silence goes, for the reason the strict parsing of the property exists - a deployment that asked for a bound is never quietly left with none.reportUnknownDialect()inCachedConnectioncannot cover this one: it keys on the url, which such a driver reads as a mysql one, and it speaks of the connect bound andpool.timeout. The driver is named rather than the url, since the driver is what this reads and what a deployment would change - and a url carries the password of the account the backend works as.The javadoc of
ddl.lock.timeoutnow names this case beside the oracle exemption, that being what an operator reads after meeting a DDL which waited anyway.Testing
JDBCDdlLockBoundTestCasegains six cases: what postgres and what mysql are told around the create of the catalog table (the readback and the value given back among them), the lock it gave up on naming the property out to the caller, and the three placements of the report - the unknown engine, the bound nobody asked for, and the oracle left alone on purpose.271 tests, 0 failures, 0 errors, 0 skips.
Passing is not enough on its own, so every guard was built with its defect put back:
testTheCreateOfTheCatalogTableIsBounded(theset local lock_timeout = 5000gone from what postgres was told),...GivesMysqlItsValueBack(expected [4] but found [2]) and...GaveUpOnNamesTheProperty(the lock reaches the operator as the bare 55P03 it arrived as)testAWaitNobodyAskedToBoundIsNotReportedAsAnUnknownEnginefails,expected [false] but found [true]testOracleIsNotReportedAsAnEngineThisBackendDoesNotKnowfails the same way, andtestAnEngineThisBackendDoesNotKnowIsReportedwith itOne thing the new cases needed, and the suite is the better for it: the storage of a case now answers
newStampConnection()itself. ReachingopenTree()means reaching the stamp of #866, whose connect would otherwise go toDriverManager- which registers every JDBC driver on the classpath. This suite needs no database and should touch none:reuseForks=falsekeeps that from reaching another class of this build, but it reaches one in an IDE, whereCatalogConnectionTestCaseneeds its own probe driver registered ahead of pgjdbc.Out of scope
ddl_lock_timeoutgives up at once by default, and ours would only loosen it.0default ofread.timeout([#885] Give a connection of the JDBC pool a read bound of its own, and take it off for a statement that carries none #934) and the unboundedbulk.timeout([#877] Bound a statement of the JDBC backend by the class of the work it belongs to #882), both shipped deliberately.create tableof the same name in an uncommitted transaction of a second session is postgres alone - mysql and oracle commit their DDL as they issue it - so a case injdbc/TestCasewould be a case about one engine wearing four engines' clothes. What each of the four is told around this create is pinned by the mock cases instead.