JDBC backend: no statement is given a query timeout, and the read bound of an established connection is gone too

[vharseko]

Describe the bug

Not one statement of the JDBC backend is given a setQueryTimeout. Nineteen sites in JDBCStorage create a PreparedStatement and execute it, and every one of them waits for the database indefinitely:

// opendj-server-legacy/src/main/java/org/opends/server/backends/jdbc/JDBCStorage.java:232
try (final PreparedStatement statement=con.prepareStatement("select v from "+getTableName(treeName)+" where h=? and k=?")){
    ...
    try (final ResultSet rc=executeResultSet(statement)) {

grep -c setQueryTimeout opendj-server-legacy/src/main/java/org/opends/server/backends/jdbc/*.java returns 0.

This is the half of #872 that lives behind a successful login. #872 bounded the establishment of a connection; once a connection is through, the entry read of read() (:232), the keyset-pagination batches of CursorImpl (:508), the upsert of put() (:386-:419), the create table / create index of openTree() (:296-:328), the select count(*) of getRecordCount() (:250), the delete from of clearTree() (:354) and the drop table of removeStorageFiles() (:152) all block for as long as the database takes.

Two bounds are needed, not one

setQueryTimeout is a logical bound, not a network one, and it is worth being explicit about that before picking it as the fix. None of the four drivers implements it with a socket read timeout: pgjdbc runs a timer that opens a connection of its own and sends a CancelRequest (bounded by cancelSignalTimeout, 10 s by default — it is in the URL of #529 for that reason), mysql-connector-j likewise opens a second connection and issues KILL QUERY, and ojdbc and mssql-jdbc send a break/attention on the same socket and wait for it to be acknowledged.

So it covers a statement that is slow or waiting for a lock while the socket is alive — and it does nothing for a socket that has gone quiet, where the cancelling connection hangs just as the original one does. The bound for that failure is a socket read timeout, and #876 deliberately lifts the one it sets for the login (socketTimeout, oracle.jdbc.ReadTimeout) as soon as the connection is established, because leaving it in place would fail every statement slower than it.

Two independent settings are therefore wanted, and they cannot share a value: a query timeout, and a read timeout for an established connection (which today is unbounded by design).

One value does not fit every call site

The nineteen sites fall into four classes with legitimate durations orders of magnitude apart:

Class	Sites	Legitimately takes
Point operations	read() :232, put/update/delete :386-:456, :575, :619	milliseconds — one row by primary key
Cursor batches	CursorImpl.fetchBatch :508	up to fetchsize rows along an index
Bulk	getRecordCount() :250 (select count(*)), clearTree() :354 (delete from <table>)	minutes on a large backend
DDL	openTree() :296-:328, removeStorageFiles() :152, :365	waits for locks rather than for work

The bulk class is not an edge path. BackendImpl.openBackend():209 logs NOTE_BACKEND_STARTED with getEntryCount(), which goes through RootContainer.getEntryCount() to getRecordCount() — a select count(*) over id2entry on every backend start. And clearTree() is what AbstractTwoPhaseImportStrategy.beforePhaseOne calls for every tree before an import writes its first record. A single 30-second default would break the start of a large backend and every import-ldif.

Session settings are not the lever

Setting the engine's own statement_timeout / MAX_EXECUTION_TIME / LOCK_TIMEOUT once per connection looks cheaper, but a pooled connection cannot carry session settings: CachedConnection.close() only rolls back, so whatever was set leaks to whoever borrows the connection next and applies to paths it was never meant for. It is the same reason #866 gives its comment statements a connection outside the pool. The bound belongs on the statement.

The lock wait is unbounded on three engines out of four

Distinct from the query timeout and worth fixing alongside it: on the DML of a pooled connection, PostgreSQL waits forever (lock_timeout defaults to 0), SQL Server waits forever (LOCK_TIMEOUT defaults to -1) and Oracle waits forever on a row lock; only MySQL is bounded, by innodb_lock_wait_timeout (50 s). #866 sets a lock timeout only on the dedicated connection it opens for its comment statements — the pooled connections have none. A server-side lock timeout also reports better than a cancelled statement: it says the operation lost a lock race rather than only that it was interrupted.

It must not disarm the transaction replay of #867

#867 replays a conflicted transaction, matching SQLState class 40 (minus 40002/40003) plus Oracle 60 and SQL Server 1205, and notes that MySQL needs no vendor code of its own because its driver already maps both a deadlock and a lock-wait timeout into class 40.

A statement cancelled by setQueryTimeout is not in class 40 (PostgreSQL reports 57014, Oracle ORA-01013, MySQL 1317, MS SQL its own), so it will not be mistaken for a conflict and replayed — which is right, and which should be verified against the drivers rather than taken on trust when this is implemented.

The risk runs the other way: a query timeout shorter than the server's lock timeout turns a conflict the replay can handle into a failure it cannot. On MySQL contention surfaces today as class 40 after 50 s and is replayed; a 30-second setQueryTimeout would turn the same wait into "query interrupted", outside the replay. Whatever default is chosen has to sit above the lock timeout of the engine, not below it.

Impact

A worker thread parks with nothing in the log, exactly as in #872 but at a point the connect bound does not cover. Every backend operation is affected, since all of them go through these statements. openTree() is the worst of them: it runs on every backend open and issues DDL, which takes a metadata lock on MySQL, a schema modification lock on SQL Server and a DDL lock on Oracle — so one unrelated transaction of another session on the same database can hold up the open of a backend, and on MySQL park every other query on that table behind it.

Expected behavior

• a query timeout per statement, by class of call site rather than one value for all of them — a short one for the point operations and cursor batches, a separate and much longer (or absent) one for getRecordCount(), clearTree() and the importer paths — configurable in the style of the org.openidentityplatform.opendj.jdbc.ttl / …jdbc.fetchsize / …jdbc.connect.timeout properties this backend already has, with 0 for no bound;
• a read timeout for an established connection, as the separate setting it has to be, for the failure a query timeout cannot see;
• a lock timeout for the pooled connections, applied per statement or per transaction rather than left on the session;
• defaults chosen above the lock timeout of the engine, so a replayable conflict stays replayable (Seek the primary key in the SQL Server upsert and retry a transaction conflict #867);
• a statement that hits its bound reported with the tree and the operation, so the log says which statement gave up rather than only that one did.

Tests cannot be docker-free here — a genuinely slow statement is needed — so the container suites are the place: another session holding an uncommitted row while a put is issued (the write must give up inside its bound rather than hang), and an import-ldif plus a getRecordCount() on a populated backend passing under the bulk bound.

Environment

master (5.2.x), all four JDBC dialects (PostgreSQL, MySQL, Oracle, MS SQL Server).

Noticed while fixing #872 (PR #876).