From aa64e76142e157cc240b8aa0cd34657befbd38fb Mon Sep 17 00:00:00 2001 From: Valera V Harseko Date: Wed, 19 Aug 2026 13:56:31 +0300 Subject: [PATCH 1/8] [#872] Bound the connect of the JDBC pool and report a connect it cannot make CachedConnection.getConnection() established connections with no bound of its own and treated every SQLException from the connect as "the server is at max_connections", retrying it recursively with a wait doubling from 1 ms and no end to it. A database that listens but does not answer, a password that is not accepted, a driver that is not in lib/extensions - each hung the caller instead of failing it, silently: every backend operation, the open of a backend and dsconfig create-backend-index on a running server included, borrows through this path. The borrow is now bounded in both phases. One connect attempt is bounded by the properties of its dialect, recognized by the prefix of the connection string, through org.openidentityplatform.opendj.jdbc.connect.timeout (30 s by default, 0 for no bound); a property the connection string sets itself keeps precedence, so the loginTimeout/socketTimeout an administrator put into db-directory by hand still governs. Not one of the four drivers bounds the attempt with a single property - the second covers the reads of the prelogin handshake, of TLS and of authentication - and that includes the SQL Server driver, whose loginTimeout leaves the prelogin read open. Where that second property is a socket read timeout for the life of the connection (mysql, oracle, sql server), it is lifted once the login is through, so a statement slower than the bound is unaffected. Only a database that accepts no further connection is retried now, under the deadline of org.openidentityplatform.opendj.jdbc.pool.timeout (60 s by default), with the backoff capped at 1 s and a throttled warning so the stall is visible in the server log; every other failure is reported to the caller. A connect whose setup fails no longer leaks the connection, a connection that cannot be rolled back is closed instead of being pooled or dropped, and a pooled connection is validated with a bound rather than with isValid(0), which means "no timeout" in the JDBC contract. CachedConnectionTestCase covers all of it without a database - every dialect against a socket that never answers and a driver of the test for the retry - and the container suites assert that the read bound of the login does not outlive it. --- .../backends/jdbc/CachedConnection.java | 340 +++++++++++++- .../jdbc/CachedConnectionTestCase.java | 443 ++++++++++++++++++ .../opends/server/backends/jdbc/TestCase.java | 21 + 3 files changed, 779 insertions(+), 25 deletions(-) create mode 100644 opendj-server-legacy/src/test/java/org/opends/server/backends/jdbc/CachedConnectionTestCase.java diff --git a/opendj-server-legacy/src/main/java/org/opends/server/backends/jdbc/CachedConnection.java b/opendj-server-legacy/src/main/java/org/opends/server/backends/jdbc/CachedConnection.java index f752ca518e..874b8162fe 100644 --- a/opendj-server-legacy/src/main/java/org/opends/server/backends/jdbc/CachedConnection.java +++ b/opendj-server-legacy/src/main/java/org/opends/server/backends/jdbc/CachedConnection.java @@ -23,9 +23,12 @@ import java.sql.*; import java.time.Duration; +import java.util.Locale; import java.util.Map; import java.util.Properties; import java.util.concurrent.*; +import java.util.concurrent.atomic.AtomicBoolean; +import java.util.concurrent.atomic.AtomicLong; public class CachedConnection implements Connection { private static final LocalizedLogger logger = LocalizedLogger.getLoggerForThisClass(); @@ -33,6 +36,28 @@ public class CachedConnection implements Connection { static final String TTL_PROPERTY = "org.openidentityplatform.opendj.jdbc.ttl"; static final long DEFAULT_TTL_MS = 15000; + /** Bounds the connect and the login of one attempt to establish a connection, in seconds; 0 for no bound. */ + static final String CONNECT_TIMEOUT_PROPERTY = "org.openidentityplatform.opendj.jdbc.connect.timeout"; + static final long DEFAULT_CONNECT_TIMEOUT_SECONDS = 30; + + /** Bounds a whole borrow - every connect attempt and every wait for a pooled connection - in seconds; 0 for no bound. */ + static final String POOL_TIMEOUT_PROPERTY = "org.openidentityplatform.opendj.jdbc.pool.timeout"; + static final long DEFAULT_POOL_TIMEOUT_SECONDS = 60; + + /** Bound of the validation of a pooled connection: isValid(0) means "no timeout" in the JDBC contract. */ + static final int VALIDATION_TIMEOUT_SECONDS = 5; + + static final long MAX_BACKOFF_MS = 1000; + static final long STALL_WARNING_AFTER_MS = 1000; + static final long STALL_WARNING_INTERVAL_MS = 10000; + + // setNetworkTimeout() takes the executor its timeout handling runs on: the drivers it is used + // with here only set a socket option in it, so it costs a call rather than a thread. + private static final Executor DIRECT_EXECUTOR = Runnable::run; + + private static final AtomicLong lastStallWarning = new AtomicLong(); + private static final AtomicBoolean readBoundWarned = new AtomicBoolean(); + final Connection parent; static LoadingCache> cached = Caffeine.newBuilder() @@ -55,19 +80,134 @@ public class CachedConnection implements Connection { * {@value #TTL_PROPERTY} system property. An invalid value is ignored in favor of the default. */ private static long getCacheTtlMillis() { - final String ttl = System.getProperty(TTL_PROPERTY); - if (ttl != null) { + return getNonNegativeProperty(TTL_PROPERTY, DEFAULT_TTL_MS); + } + + /** + * Returns the value of a numeric system property, ignoring a value that is not a non-negative + * number in favor of the default. + */ + private static long getNonNegativeProperty(String name, long defaultValue) { + final String value = System.getProperty(name); + if (value != null) { try { - final long millis = Long.parseLong(ttl.trim()); - if (millis >= 0) { - return millis; + final long parsed = Long.parseLong(value.trim()); + if (parsed >= 0) { + return parsed; } } catch (NumberFormatException ignored) { } - logger.warn(LocalizableMessage.raw("Ignoring invalid value \"%s\" of the %s property, using %d ms", - ttl, TTL_PROPERTY, DEFAULT_TTL_MS)); + logger.warn(LocalizableMessage.raw("Ignoring invalid value \"%s\" of the %s property, using %d", + value, name, defaultValue)); + } + return defaultValue; + } + + /** + * The drivers this backend is used with, recognized by the prefix of the connection string, + * together with the properties that bound one attempt to establish a connection. Not one of + * them bounds the attempt with a single property: the one named first covers the socket + * connect, and the login behind it - the reads of the prelogin handshake, of TLS and of + * authentication, the phase a proxy at its connection limit or a moved VIP leaves unanswered - + * needs the second. That holds for the SQL Server driver too, whose loginTimeout leaves the + * read of the prelogin answer unbounded (CachedConnectionTestCase covers every one of them + * against a socket that never answers). + */ + enum ConnectDialect { + /** postgresql: both properties take seconds; loginTimeout bounds the login the driver runs on a thread of its own. */ + POSTGRES("jdbc:postgresql:", "connectTimeout", 1, "loginTimeout", 1, false, new int[]{}), + /** mysql: both properties take milliseconds; socketTimeout is a socket read timeout that outlives the login. */ + MYSQL("jdbc:mysql:", "connectTimeout", 1000, "socketTimeout", 1000, true, new int[]{1040, 1203}), + /** oracle: both properties take milliseconds; ReadTimeout is a socket read timeout that outlives the login. */ + ORACLE("jdbc:oracle:", "oracle.net.CONNECT_TIMEOUT", 1000, "oracle.jdbc.ReadTimeout", 1000, true, + new int[]{20, 12516, 12518, 12519, 12520}), + /** ms sql server: loginTimeout takes seconds, socketTimeout milliseconds; the latter is a socket read timeout that outlives the login. */ + MICROSOFT("jdbc:sqlserver:", "loginTimeout", 1, "socketTimeout", 1000, true, new int[]{17809, 10928, 10929}); + + final String urlPrefix; + final String connectProperty; + final int connectUnitsPerSecond; + final String readProperty; + final int readUnitsPerSecond; + /** whether the read bound of the login stays in force for every statement issued afterwards */ + final boolean readBoundOutlivesLogin; + /** the vendor codes of this dialect for "no further connection is accepted" */ + final int[] connectionLimitCodes; + + ConnectDialect(String urlPrefix, String connectProperty, int connectUnitsPerSecond, + String readProperty, int readUnitsPerSecond, boolean readBoundOutlivesLogin, + int[] connectionLimitCodes) { + this.urlPrefix = urlPrefix; + this.connectProperty = connectProperty; + this.connectUnitsPerSecond = connectUnitsPerSecond; + this.readProperty = readProperty; + this.readUnitsPerSecond = readUnitsPerSecond; + this.readBoundOutlivesLogin = readBoundOutlivesLogin; + this.connectionLimitCodes = connectionLimitCodes; + } + + /** The dialect of a connection string, or null for a driver whose property names are not known here. */ + static ConnectDialect of(String connectionString) { + final String url = connectionString.toLowerCase(Locale.ROOT); + for (final ConnectDialect dialect : values()) { + if (url.startsWith(dialect.urlPrefix)) { + return dialect; + } + } + return null; + } + + /** + * Fills in the properties bounding one connect attempt, leaving out every property the + * connection string sets itself - an explicit setting of the administrator keeps + * precedence, and the SQL Server driver gives a supplied property precedence over the url. + * Returns whether a read bound outliving the login was set and has to be lifted once the + * connection is established. + */ + boolean bound(String connectionString, Properties properties, long timeoutSeconds) { + if (!declaredInUrl(connectionString, connectProperty)) { + properties.setProperty(connectProperty, Long.toString(timeoutSeconds * connectUnitsPerSecond)); + } + if (readProperty != null && !declaredInUrl(connectionString, readProperty)) { + properties.setProperty(readProperty, Long.toString(timeoutSeconds * readUnitsPerSecond)); + return readBoundOutlivesLogin; + } + return false; + } + + boolean isConnectionLimit(SQLException e) { + for (final int code : connectionLimitCodes) { + if (e.getErrorCode() == code) { + return true; + } + } + return false; + } + + // Whether the connection string sets this property itself. The dialects separate their + // parameters differently - "?a=1&b=2" (postgresql, mysql), ";a=1;b=2" (sql server), + // "(A=1)" inside the descriptor of an oracle tns url, where the property also goes by the + // last segment of its name alone - so a parameter is recognized by the delimiter in front + // of it and the "=" behind it rather than by parsing the url syntax of every driver. + private static boolean declaredInUrl(String connectionString, String property) { + if (containsParameter(connectionString, property)) { + return true; + } + final int dot = property.lastIndexOf('.'); + return dot >= 0 && containsParameter(connectionString, property.substring(dot + 1)); + } + + private static boolean containsParameter(String connectionString, String property) { + final String url = connectionString.toLowerCase(Locale.ROOT); + final String name = property.toLowerCase(Locale.ROOT); + for (int i = url.indexOf(name); i >= 0; i = url.indexOf(name, i + name.length())) { + final int end = i + name.length(); + if (i > 0 && "?&;(,".indexOf(url.charAt(i - 1)) >= 0 && end < url.length() && url.charAt(end) == '=') { + return true; + } + } + return false; } - return DEFAULT_TTL_MS; } final String connectionString; @@ -76,32 +216,175 @@ public CachedConnection(String connectionString, Connection parent) { this.parent = parent; } + /** + * Borrows a connection: a usable one out of the pool, or a newly established one. Bounded in + * both phases - every operation of this backend, the open of a backend and the import + * included, comes through here, and an unbounded borrow turns a database that listens but does + * not answer into a hang rather than into an error the caller can report. + */ static Connection getConnection(String connectionString) throws Exception { - return getConnection(connectionString, 0); + final ConnectDialect dialect = ConnectDialect.of(connectionString); + final long connectTimeoutSeconds = Math.min( + getNonNegativeProperty(CONNECT_TIMEOUT_PROPERTY, DEFAULT_CONNECT_TIMEOUT_SECONDS), Integer.MAX_VALUE / 1000); + final long poolTimeoutSeconds = getNonNegativeProperty(POOL_TIMEOUT_PROPERTY, DEFAULT_POOL_TIMEOUT_SECONDS); + final long startedAt = System.currentTimeMillis(); + final long deadline = (poolTimeoutSeconds == 0 || poolTimeoutSeconds >= Long.MAX_VALUE / 1000) + ? Long.MAX_VALUE : startedAt + poolTimeoutSeconds * 1000; + long waitMs = 0; + long backoffMs = 0; + int attempts = 0; + while (true) { + final CachedConnection pooled = poll(connectionString, waitMs); + if (pooled != null) { + return pooled; + } + attempts++; + try { + return connect(connectionString, dialect, connectTimeoutSeconds); + } catch (SQLException e) { + // A database that accepts no further connection is the one failure worth waiting + // out: one of ours is going to come back to the pool. Everything else - a password + // that is not accepted, a database that is down, a driver that is not on the + // classpath - is reported to the caller instead of being retried behind its back. + if (!isConnectionLimit(e, dialect)) { + throw e; + } + final long remaining = deadline - System.currentTimeMillis(); + if (remaining <= 0) { + throw new SQLTimeoutException("no connection to " + safeUrl(connectionString) + " could be borrowed within " + + poolTimeoutSeconds + "s (" + attempts + " attempts): the database accepts no further connection" + + " and none was returned to the pool", e); + } + backoffMs = Math.min(backoffMs == 0 ? 1 : backoffMs * 2, MAX_BACKOFF_MS); + waitMs = Math.min(backoffMs, remaining); + warnStall(connectionString, attempts, startedAt, e); + } + } } - static Connection getConnection(String connectionString, final int waitTime) throws Exception { - CachedConnection con = cached.get(connectionString).poll(waitTime, TimeUnit.MILLISECONDS); - + /** Takes a usable connection out of the pool, waiting up to waitMs for one to be returned to it. */ + private static CachedConnection poll(String connectionString, long waitMs) throws InterruptedException { + CachedConnection con = cached.get(connectionString).poll(waitMs, TimeUnit.MILLISECONDS); while (con != null) { - if (!con.isValid(0)) { - try { - con.parent.close(); - } catch (SQLException e) { - con = null; - } - con = cached.get(connectionString).poll(); - } else { + if (isUsable(con)) { return con; } + closeQuietly(con.parent); + con = cached.get(connectionString).poll(); + } + return null; + } + + private static boolean isUsable(CachedConnection con) { + try { + // The validation needs a bound of its own: isValid(0) means "no timeout" in the JDBC + // contract, and a connection whose socket is half-open answers it no sooner than it + // answers anything else. + return con.isValid(VALIDATION_TIMEOUT_SECONDS); + } catch (SQLException e) { // a driver reporting the validation as an error: discard it + return false; } + } + + private static CachedConnection connect(String connectionString, ConnectDialect dialect, long connectTimeoutSeconds) + throws SQLException { + // A driver is free to write into the map it is handed, so it gets one of its own. + final Properties properties = new Properties(); + final boolean readBoundSet = dialect != null && connectTimeoutSeconds > 0 + && dialect.bound(connectionString, properties, connectTimeoutSeconds); + final Connection conNew = DriverManager.getConnection(connectionString, properties); try { - final Connection conNew = DriverManager.getConnection(connectionString); + // still under the read bound: both of these are round trips of their own conNew.setAutoCommit(false); conNew.setTransactionIsolation(TRANSACTION_READ_COMMITTED); - return new CachedConnection(connectionString, conNew); - } catch (SQLException e) { // max_connection server error: try recursion for reuse connection - return getConnection(connectionString, (waitTime == 0) ? 1 : waitTime * 2); + if (readBoundSet) { + relaxReadBound(conNew); + } + } catch (SQLException e) { // nothing holds this connection yet: it would leak + closeQuietly(conNew); + throw e; + } + return new CachedConnection(connectionString, conNew); + } + + // The second bound of the login is a socket read timeout on mysql, oracle and sql server, in + // force for the whole life of the connection: left in place it would break every statement + // slower than it - an import batch, the statistics of a freshly loaded table - so it is lifted + // as soon as the login is through, restoring the behaviour of a connection this class + // established before. A read bound the connection string sets itself is never touched here: + // it is not set at all, so nothing of the administrator's is lifted along with it. + private static void relaxReadBound(Connection con) { + try { + con.setNetworkTimeout(DIRECT_EXECUTOR, 0); + } catch (SQLException | RuntimeException e) { + if (readBoundWarned.compareAndSet(false, true)) { + logger.warn(LocalizableMessage.raw( + "The read bound of the login could not be lifted (%s): statements taking longer than the %s" + + " property will fail on connections of this backend", e.getMessage(), CONNECT_TIMEOUT_PROPERTY)); + } + } + } + + /** Whether the database refused the connection because it accepts no further one. */ + static boolean isConnectionLimit(SQLException e, ConnectDialect dialect) { + for (Throwable t = e; t != null; t = t.getCause()) { + if (t instanceof SQLException) { + final SQLException sql = (SQLException) t; + // class 53, insufficient_resources, is how the standard - and postgresql, with + // 53300 too_many_connections - reports a server taking no further connection + final String sqlState = sql.getSQLState(); + if ((sqlState != null && sqlState.startsWith("53")) + || (dialect != null && dialect.isConnectionLimit(sql))) { + return true; + } + } + } + return false; + } + + // A stall has to reach the server log: without it a database accepting no further connection + // is indistinguishable from a hang. Throttled, since every operation of the backend borrows + // through here and would otherwise log a copy of its own. + private static void warnStall(String connectionString, int attempts, long startedAt, SQLException cause) { + final long now = System.currentTimeMillis(); + if (now - startedAt < STALL_WARNING_AFTER_MS) { + return; + } + final long last = lastStallWarning.get(); + if (now - last >= STALL_WARNING_INTERVAL_MS && lastStallWarning.compareAndSet(last, now)) { + logger.warn(LocalizableMessage.raw( + "%s accepts no further connection: waiting %d ms for a pooled one so far (%d attempts), last error: %s", + safeUrl(connectionString), now - startedAt, attempts, cause.getMessage())); + } + } + + // The connection string carries the credentials of the backend, so it is never logged as it + // stands. Parameters - "?user=...&password=..." on postgresql and mysql, ";password=..." on + // sql server - are cut off behind their first separator, while the credentials of a url that + // carries them in front of an "@" ("user/password@//host" on an oracle thin url, the userinfo + // of a url) are cut off in front of it, leaving the scheme and the host they stand between. + static String safeUrl(String connectionString) { + int cut = connectionString.length(); + for (final char separator : new char[]{'?', ';'}) { + final int at = connectionString.indexOf(separator); + if (at >= 0 && at < cut) { + cut = at; + } + } + final String url = connectionString.substring(0, cut); + final int at = url.indexOf('@'); + if (at < 0) { + return url; + } + final int scheme = url.indexOf(':', "jdbc:".length()) + 1; // the end of "jdbc::" + return url.substring(0, scheme) + url.substring(at); + } + + private static void closeQuietly(Connection con) { + try { + con.close(); + } catch (SQLException e) { + // ignore: it is on its way out anyway } } @@ -147,7 +430,14 @@ public void rollback() throws SQLException { @Override public void close() throws SQLException { - rollback(); + try { + rollback(); + } catch (SQLException e) { + // A connection that cannot be rolled back must not be handed to the next borrower - + // and must not be dropped on the floor either: nothing else holds it any more. + closeQuietly(parent); + throw e; + } cached.get(connectionString).add(this); } diff --git a/opendj-server-legacy/src/test/java/org/opends/server/backends/jdbc/CachedConnectionTestCase.java b/opendj-server-legacy/src/test/java/org/opends/server/backends/jdbc/CachedConnectionTestCase.java new file mode 100644 index 0000000000..1590536363 --- /dev/null +++ b/opendj-server-legacy/src/test/java/org/opends/server/backends/jdbc/CachedConnectionTestCase.java @@ -0,0 +1,443 @@ +/* + * The contents of this file are subject to the terms of the Common Development and + * Distribution License (the License). You may not use this file except in compliance with the + * License. + * + * You can obtain a copy of the License at legal/CDDLv1.0.txt. See the License for the + * specific language governing permission and limitations under the License. + * + * When distributing Covered Software, include this CDDL Header Notice in each file and include + * the License file at legal/CDDLv1.0.txt. If applicable, add the following below the CDDL + * Header, with the fields enclosed by brackets [] replaced by your own identifying + * information: "Portions Copyright [year] [name of copyright owner]". + * + * Copyright 2026 3A Systems, LLC. + */ +package org.opends.server.backends.jdbc; + +import org.opends.server.DirectoryServerTestCase; +import org.testng.annotations.AfterClass; +import org.testng.annotations.AfterMethod; +import org.testng.annotations.BeforeClass; +import org.testng.annotations.Test; + +import java.net.InetAddress; +import java.net.ServerSocket; +import java.sql.Connection; +import java.sql.Driver; +import java.sql.DriverManager; +import java.sql.DriverPropertyInfo; +import java.sql.SQLException; +import java.sql.SQLTimeoutException; +import java.util.Properties; +import java.util.concurrent.ExecutionException; +import java.util.concurrent.FutureTask; +import java.util.concurrent.TimeUnit; +import java.util.concurrent.TimeoutException; +import java.util.concurrent.atomic.AtomicInteger; +import java.util.logging.Logger; + +import static org.mockito.Mockito.anyInt; +import static org.mockito.Mockito.doThrow; +import static org.mockito.Mockito.mock; +import static org.mockito.Mockito.never; +import static org.mockito.Mockito.verify; +import static org.mockito.Mockito.when; +import static org.testng.Assert.assertEquals; +import static org.testng.Assert.assertFalse; +import static org.testng.Assert.assertNotNull; +import static org.testng.Assert.assertNull; +import static org.testng.Assert.assertSame; +import static org.testng.Assert.assertTrue; +import static org.testng.Assert.fail; + +/** + * The pool every operation of the JDBC backend borrows from must bound both of its phases and + * report a connect it cannot make, rather than retrying it out of sight of the caller (#872). + * Needs no database: the dialects are exercised against a socket that never answers and against a + * driver of this test, so a regression fails the build wherever it runs. + */ +@SuppressWarnings("javadoc") +@Test(groups = { "precommit", "jdbc" }, sequential = true) +public class CachedConnectionTestCase extends DirectoryServerTestCase { + + /** A connect attempt of a bounded dialect must give up in about this long, plus room for a slow machine. */ + private static final long BOUND_SECONDS = 2; + private static final long BOUND_MARGIN_MS = 60000; + + private final StubDriver stub = new StubDriver(); + + @BeforeClass + public void registerStubDriver() throws Exception { + DriverManager.registerDriver(stub); + } + + @AfterClass + public void deregisterStubDriver() throws Exception { + DriverManager.deregisterDriver(stub); + } + + @AfterMethod + public void clearProperties() { + System.clearProperty(CachedConnection.CONNECT_TIMEOUT_PROPERTY); + System.clearProperty(CachedConnection.POOL_TIMEOUT_PROPERTY); + } + + /** + * A driver that is not on the classpath - the JDBC backend needs one dropped into + * lib/extensions by hand - is a configuration error the caller has to see. Retried, it is + * indistinguishable from a database that hangs. + */ + @Test(timeOut = 120000) + public void testMissingDriverIsReportedAtOnce() throws Exception { + final long startedAt = System.currentTimeMillis(); + try { + CachedConnection.getConnection("jdbc:nosuchengine://127.0.0.1:5432/opendj"); + fail("a connection string no registered driver accepts must be reported"); + } catch (SQLException expected) { + assertTrue(expected.getMessage().contains("No suitable driver"), expected.getMessage()); + } + assertElapsedWithinBound(startedAt, 0); + } + + /** + * A database that is not listening at all: every dialect reports it instead of retrying the + * refused connect until the caller gives up on the operation. + */ + @Test(timeOut = 120000) + public void testRefusedConnectIsReportedAtOnce() throws Exception { + final int closedPort = closedPort(); + System.setProperty(CachedConnection.CONNECT_TIMEOUT_PROPERTY, Long.toString(BOUND_SECONDS)); + for (final String url : urlsOf(closedPort)) { + final long startedAt = System.currentTimeMillis(); + try { + CachedConnection.getConnection(url); + fail("a refused connect must be reported: " + CachedConnection.safeUrl(url)); + } catch (SQLException expected) { + // the failure of the moment, reported rather than retried + } + assertElapsedWithinBound(startedAt, BOUND_SECONDS * 1000); + } + } + + /** + * The failure this bound exists for: a database that completes the TCP connection and then + * says nothing - a moved VIP, a proxy at its connection limit, a host that lost its answer - + * leaving the login of the driver, and with it the operation, without an end. The connection + * of the accept queue is never answered here, so every dialect has to give up on its own. + */ + @Test(timeOut = 300000) + public void testLoginIsBoundedWhenTheDatabaseNeverAnswers() throws Exception { + System.setProperty(CachedConnection.CONNECT_TIMEOUT_PROPERTY, Long.toString(BOUND_SECONDS)); + // a socket that is bound and never accepted: the kernel completes the handshake, so the + // connect of the driver succeeds and every read of the login that follows hangs + try (final ServerSocket blackhole = new ServerSocket(0, 50, InetAddress.getLoopbackAddress())) { + for (final String url : urlsOf(blackhole.getLocalPort())) { + // borrowed on a thread of its own: a bound that a driver does not honour has to + // fail this test at once, and not by hanging the run it is part of + final FutureTask borrow = new FutureTask<>(() -> CachedConnection.getConnection(url)); + final Thread thread = new Thread(borrow, "borrow-" + CachedConnection.safeUrl(url)); + thread.setDaemon(true); + thread.start(); + try { + final Connection con = borrow.get(BOUND_SECONDS * 1000 + BOUND_MARGIN_MS, TimeUnit.MILLISECONDS); + fail("a database that never answers must not hand out a connection: " + con); + } catch (TimeoutException e) { + fail("the login of " + CachedConnection.safeUrl(url) + " is not bounded: it never gave up"); + } catch (ExecutionException expected) { + assertTrue(expected.getCause() instanceof SQLException, String.valueOf(expected.getCause())); + } + } + } + } + + /** Pool exhaustion stays a retry - one of our own connections is on its way back to the pool. */ + @Test(timeOut = 120000) + public void testConnectionLimitIsRetried() throws Exception { + final String url = StubDriver.PREFIX + "retried"; + stub.failWith(tooManyConnections(), 2); + System.setProperty(CachedConnection.POOL_TIMEOUT_PROPERTY, "30"); + + final Connection con = CachedConnection.getConnection(url); + + assertNotNull(con); + assertEquals(stub.attempts.get(), 3, "the connect must be retried while the database is at its limit"); + } + + /** ... but under a deadline: the retry used to double its wait from 1 ms with no end to it. */ + @Test(timeOut = 120000) + public void testConnectionLimitGivesUpAtTheDeadline() throws Exception { + final String url = StubDriver.PREFIX + "deadline"; + stub.failWith(tooManyConnections(), StubDriver.ALWAYS); + System.setProperty(CachedConnection.POOL_TIMEOUT_PROPERTY, "2"); + + final long startedAt = System.currentTimeMillis(); + try { + CachedConnection.getConnection(url); + fail("a database that stays at its connection limit must be reported, not waited out forever"); + } catch (SQLTimeoutException expected) { + assertTrue(expected.getMessage().contains("2s"), expected.getMessage()); + assertEquals(((SQLException) expected.getCause()).getSQLState(), "53300"); + } + final long elapsed = System.currentTimeMillis() - startedAt; + assertTrue(elapsed >= 2000, "gave up after " + elapsed + " ms, before the deadline it was given"); + assertElapsedWithinBound(startedAt, 2000); + assertTrue(stub.attempts.get() > 1, "the connect must be retried while the deadline lasts"); + } + + /** + * Every other failure is the caller's to report. A password the database does not accept is + * never going to be accepted by waiting, and the retry that swallowed it left the operation + * hanging with nothing in the log. + */ + @Test(timeOut = 120000) + public void testRejectedLoginIsNotRetried() throws Exception { + final String url = StubDriver.PREFIX + "rejected"; + stub.failWith(new SQLException("password authentication failed", "28P01"), StubDriver.ALWAYS); + System.setProperty(CachedConnection.POOL_TIMEOUT_PROPERTY, "30"); + + try { + CachedConnection.getConnection(url); + fail("a rejected login must be reported to the caller"); + } catch (SQLException expected) { + assertEquals(expected.getSQLState(), "28P01"); + } + assertEquals(stub.attempts.get(), 1, "a rejected login must be attempted once"); + } + + /** A connection the setup of which failed belongs to nobody: it has to be closed, not leaked. */ + @Test(timeOut = 120000) + public void testConnectionIsClosedWhenItsSetupFails() throws Exception { + final String url = StubDriver.PREFIX + "setup-failure"; + final Connection broken = mock(Connection.class); + doThrow(new SQLException("read only")).when(broken).setAutoCommit(false); + stub.answerWith(broken); + + try { + CachedConnection.getConnection(url); + fail("a connection that cannot be set up must be reported"); + } catch (SQLException expected) { + assertEquals(expected.getMessage(), "read only"); + } + verify(broken).close(); + } + + /** A pooled connection that no longer validates is closed and replaced, not handed out. */ + @Test(timeOut = 120000) + public void testBrokenPooledConnectionIsDiscarded() throws Exception { + final String url = StubDriver.PREFIX + "broken-pooled"; + final Connection stale = mock(Connection.class); + when(stale.isValid(anyInt())).thenReturn(false); + CachedConnection.cached.get(url).add(new CachedConnection(url, stale)); + final Connection fresh = mock(Connection.class); + when(fresh.isValid(anyInt())).thenReturn(true); + stub.answerWith(fresh); + + final Connection borrowed = CachedConnection.getConnection(url); + + assertSame(((CachedConnection) borrowed).parent, fresh); + verify(stale).close(); + // the validation of a pooled connection needs a bound of its own as well + verify(stale, never()).isValid(0); + verify(stale).isValid(CachedConnection.VALIDATION_TIMEOUT_SECONDS); + } + + /** A connection that cannot be rolled back must not go back into the pool - nor be dropped. */ + @Test(timeOut = 120000) + public void testConnectionThatCannotBeRolledBackIsClosed() throws Exception { + final String url = StubDriver.PREFIX + "rollback-failure"; + final Connection parent = mock(Connection.class); + doThrow(new SQLException("connection is closed")).when(parent).rollback(); + + try { + new CachedConnection(url, parent).close(); + fail("a failed rollback must be reported"); + } catch (SQLException expected) { + assertEquals(expected.getMessage(), "connection is closed"); + } + verify(parent).close(); + assertTrue(CachedConnection.cached.get(url).isEmpty(), "a connection that cannot be rolled back was pooled"); + } + + @Test + public void testDialectIsRecognizedByTheConnectionString() throws Exception { + assertEquals(CachedConnection.ConnectDialect.of("jdbc:postgresql://h:5432/db"), CachedConnection.ConnectDialect.POSTGRES); + assertEquals(CachedConnection.ConnectDialect.of("jdbc:mysql://h:3306/db"), CachedConnection.ConnectDialect.MYSQL); + assertEquals(CachedConnection.ConnectDialect.of("jdbc:oracle:thin:@//h:1521/svc"), CachedConnection.ConnectDialect.ORACLE); + assertEquals(CachedConnection.ConnectDialect.of("jdbc:sqlserver://h:1433;databaseName=db"), CachedConnection.ConnectDialect.MICROSOFT); + assertNull(CachedConnection.ConnectDialect.of("jdbc:h2:mem:db"), "an unknown engine must not be fed the properties of another"); + } + + /** Both phases are bounded, in the units of the driver: the connect alone leaves the login open. */ + @Test + public void testBothPhasesOfTheLoginAreBounded() throws Exception { + final Properties postgres = new Properties(); + assertFalse(CachedConnection.ConnectDialect.POSTGRES.bound("jdbc:postgresql://h:5432/db", postgres, 7)); + assertEquals(postgres.getProperty("connectTimeout"), "7"); + assertEquals(postgres.getProperty("loginTimeout"), "7"); + + final Properties mysql = new Properties(); + assertTrue(CachedConnection.ConnectDialect.MYSQL.bound("jdbc:mysql://h:3306/db", mysql, 7), + "the read bound of mysql outlives the login and has to be lifted"); + assertEquals(mysql.getProperty("connectTimeout"), "7000"); + assertEquals(mysql.getProperty("socketTimeout"), "7000"); + + final Properties oracle = new Properties(); + assertTrue(CachedConnection.ConnectDialect.ORACLE.bound("jdbc:oracle:thin:@//h:1521/svc", oracle, 7)); + assertEquals(oracle.getProperty("oracle.net.CONNECT_TIMEOUT"), "7000"); + assertEquals(oracle.getProperty("oracle.jdbc.ReadTimeout"), "7000"); + + // the loginTimeout of the sql server driver leaves the read of the prelogin answer open + final Properties microsoft = new Properties(); + assertTrue(CachedConnection.ConnectDialect.MICROSOFT.bound("jdbc:sqlserver://h:1433;databaseName=db", microsoft, 7)); + assertEquals(microsoft.getProperty("loginTimeout"), "7"); + assertEquals(microsoft.getProperty("socketTimeout"), "7000"); + } + + /** + * A bound the administrator put into the connection string by hand - the only workaround this + * backend had - keeps precedence, property by property. + */ + @Test + public void testConnectionStringKeepsPrecedence() throws Exception { + final Properties postgres = new Properties(); + CachedConnection.ConnectDialect.POSTGRES.bound( + "jdbc:postgresql://h:5432/db?user=u&password=p&loginTimeout=30&socketTimeout=300", postgres, 7); + assertNull(postgres.getProperty("loginTimeout"), "the setting of the connection string was overridden"); + assertEquals(postgres.getProperty("connectTimeout"), "7", "the property it leaves open must still be bounded"); + + // the sql server driver gives a supplied property precedence over the one of the url + final Properties microsoft = new Properties(); + CachedConnection.ConnectDialect.MICROSOFT.bound("jdbc:sqlserver://h:1433;loginTimeout=45;databaseName=db", microsoft, 7); + assertNull(microsoft.getProperty("loginTimeout"), "the setting of the connection string was overridden"); + assertEquals(microsoft.getProperty("socketTimeout"), "7000"); + + // inside the descriptor of an oracle tns url the property goes by the last segment of its name + final Properties oracle = new Properties(); + CachedConnection.ConnectDialect.ORACLE.bound( + "jdbc:oracle:thin:@(DESCRIPTION=(CONNECT_TIMEOUT=3)(ADDRESS=(HOST=h)(PORT=1521)))", oracle, 7); + assertNull(oracle.getProperty("oracle.net.CONNECT_TIMEOUT")); + assertEquals(oracle.getProperty("oracle.jdbc.ReadTimeout"), "7000"); + + // a name that only appears as the tail of another parameter is not a setting of its own + final Properties mysql = new Properties(); + CachedConnection.ConnectDialect.MYSQL.bound("jdbc:mysql://h:3306/db?xconnectTimeout=1&socketTimeoutX=2", mysql, 7); + assertEquals(mysql.getProperty("connectTimeout"), "7000"); + assertEquals(mysql.getProperty("socketTimeout"), "7000"); + } + + /** The connection string holds the credentials of the backend: a stall report must not carry them. */ + @Test + public void testLoggedConnectionStringCarriesNoCredentials() throws Exception { + assertEquals(CachedConnection.safeUrl("jdbc:postgresql://h:5432/db?user=u&password=secret"), "jdbc:postgresql://h:5432/db"); + assertEquals(CachedConnection.safeUrl("jdbc:sqlserver://h:1433;databaseName=db;password=secret"), "jdbc:sqlserver://h:1433"); + assertEquals(CachedConnection.safeUrl("jdbc:oracle:thin:scott/secret@//h:1521/svc"), "jdbc:oracle:@//h:1521/svc"); + assertEquals(CachedConnection.safeUrl("jdbc:mysql://u:secret@h:3306/db"), "jdbc:mysql:@h:3306/db"); + assertEquals(CachedConnection.safeUrl("jdbc:oracle:thin:@//h:1521/svc"), "jdbc:oracle:@//h:1521/svc"); + } + + private static SQLException tooManyConnections() { + // 53300, too_many_connections, of the insufficient_resources class + return new SQLException("sorry, too many clients already", "53300"); + } + + /** A connection string of every dialect pointing at one host and port. */ + private static String[] urlsOf(int port) { + return new String[]{ + "jdbc:postgresql://127.0.0.1:" + port + "/opendj?user=opendj&password=opendj", + "jdbc:mysql://127.0.0.1:" + port + "/opendj?user=opendj&password=opendj", + "jdbc:oracle:thin:opendj/opendj@//127.0.0.1:" + port + "/free", + "jdbc:sqlserver://127.0.0.1:" + port + ";databaseName=opendj;user=opendj;password=opendj;encrypt=false" + }; + } + + private static int closedPort() throws Exception { + try (final ServerSocket socket = new ServerSocket(0, 1, InetAddress.getLoopbackAddress())) { + return socket.getLocalPort(); + } // closed again: nothing listens there any more + } + + private static void assertElapsedWithinBound(long startedAt, long boundMs) { + final long elapsed = System.currentTimeMillis() - startedAt; + assertTrue(elapsed < boundMs + BOUND_MARGIN_MS, "gave up only after " + elapsed + " ms"); + } + + /** + * Stands in for a database whose answer to a connect is the point of the test: the vendor + * codes and SQL states below are what the retry has to tell apart, and no engine is needed to + * produce them. + */ + private static final class StubDriver implements Driver { + static final String PREFIX = "jdbc:opendj-stub:"; + static final int ALWAYS = -1; + + final AtomicInteger attempts = new AtomicInteger(); + private volatile SQLException failure; + private volatile int failuresLeft; + private volatile Connection answer; + + void failWith(SQLException failure, int times) { + this.failure = failure; + this.failuresLeft = times; + this.answer = null; + this.attempts.set(0); + } + + void answerWith(Connection answer) { + this.failure = null; + this.failuresLeft = 0; + this.answer = answer; + this.attempts.set(0); + } + + @Override + public Connection connect(String url, Properties info) throws SQLException { + if (!acceptsURL(url)) { + return null; + } + attempts.incrementAndGet(); + if (failuresLeft != 0) { + if (failuresLeft > 0) { + failuresLeft--; + } + throw failure; + } + if (answer != null) { + return answer; + } + final Connection con = mock(Connection.class); + when(con.isValid(anyInt())).thenReturn(true); + return con; + } + + @Override + public boolean acceptsURL(String url) { + return url != null && url.startsWith(PREFIX); + } + + @Override + public DriverPropertyInfo[] getPropertyInfo(String url, Properties info) { + return new DriverPropertyInfo[0]; + } + + @Override + public int getMajorVersion() { + return 1; + } + + @Override + public int getMinorVersion() { + return 0; + } + + @Override + public boolean jdbcCompliant() { + return false; + } + + @Override + public Logger getParentLogger() { + return Logger.getLogger(StubDriver.class.getName()); + } + } +} diff --git a/opendj-server-legacy/src/test/java/org/opends/server/backends/jdbc/TestCase.java b/opendj-server-legacy/src/test/java/org/opends/server/backends/jdbc/TestCase.java index 472f62fc9a..e2bd45a980 100644 --- a/opendj-server-legacy/src/test/java/org/opends/server/backends/jdbc/TestCase.java +++ b/opendj-server-legacy/src/test/java/org/opends/server/backends/jdbc/TestCase.java @@ -130,6 +130,27 @@ public void cleanUp() throws Exception { protected abstract String getJdbcUrl(); + /** + * The second property bounding a login is a socket read timeout on mysql, oracle and sql + * server: in force for the whole life of the connection it would fail every statement slower + * than it - an import batch, the statistics of a freshly loaded table - so it has to be lifted + * as soon as the login is through (#872). + */ + @Test + public void testLoginBoundDoesNotOutliveTheLogin() throws Exception { + final String url = createBackendCfg().getDBDirectory(); + System.setProperty(CachedConnection.CONNECT_TIMEOUT_PROPERTY, "2"); + try { + // a pooled connection would be handed back without being established again + CachedConnection.cached.invalidate(url); + try (final Connection con = CachedConnection.getConnection(url)) { + assertEquals(con.getNetworkTimeout(), 0, "the read bound of the login is still in force"); + } + } finally { + System.clearProperty(CachedConnection.CONNECT_TIMEOUT_PROPERTY); + } + } + private static ByteString key(int i) { return ByteString.valueOfUtf8(String.format("key%02d", i)); } From e83d0026852804665a594a9feeaec81329f5f39d Mon Sep 17 00:00:00 2001 From: Valera V Harseko Date: Wed, 19 Aug 2026 18:51:03 +0300 Subject: [PATCH 2/8] [#872] Wait out a database on its way up and bound what the review found open A database that is starting up, recovering or shutting down answers a connect with a state of its own - 57P03 on postgresql, ORA-01033/01034/01089, 1053 on mysql, 921/922/927 and 40613 on sql server - and clears it in seconds. Only pool exhaustion was waited out, so a backend whose database restarted together with the server stayed locked down until the next restart of it: nothing above JDBCStorage.open() attempts the open a second time. Those states are retried alongside pool exhaustion now, under the same pool deadline. ORA-12514 is left out of them: it is what a service name of a typo answers as well. The deadline is applied where it was missing. Draining the pool costs a round trip per connection and the pool has no bound on the number it holds, so the drain stops at the deadline of the borrow; and one connect attempt is bounded by what is left of that deadline, so a borrow can no longer outlive its pool timeout by a whole connect timeout - which is what the property promised. The validation of a pooled connection is bounded at the socket rather than through isValid(n) alone: the sql server driver turns that argument into a query timeout (setQueryTimeout, then "SELECT 1"), which needs an answer from the server to fire at all, and the read bound of the login was lifted the moment the connection was established. A tighter bound of the connection string is left alone, and a connection whose bound cannot be put back is discarded instead of being handed out carrying it. Also from the review: a setup failing with an unchecked exception no longer leaks the connection; pool exhaustion is 53300 rather than the whole insufficient_resources class, and getNextException() is walked along with the causes; an url is stripped of its credentials before its parameters and with the separator of its own dialect, so a password holding a ";" no longer reaches the log; a parameter is recognized the way its driver recognizes it, case-sensitively for pgjdbc alone; the read bound of an oracle descriptor (RECV_TIMEOUT, oracle.net.READ_TIMEOUT) counts as one of the administrator, so ours is neither set on top of it nor lifted with it; loginTimeout stays inside the [0, 65535] the sql server driver validates it against; and the warning for a read bound that cannot be set is throttled rather than given once per JVM, as is the stall warning, now kept per connection string. CachedConnectionTestCase covers each of these without a database: 23 tests. --- .../backends/jdbc/CachedConnection.java | 332 +++++++++++++----- .../jdbc/CachedConnectionTestCase.java | 208 +++++++++++ 2 files changed, 458 insertions(+), 82 deletions(-) diff --git a/opendj-server-legacy/src/main/java/org/opends/server/backends/jdbc/CachedConnection.java b/opendj-server-legacy/src/main/java/org/opends/server/backends/jdbc/CachedConnection.java index 874b8162fe..a1184bc815 100644 --- a/opendj-server-legacy/src/main/java/org/opends/server/backends/jdbc/CachedConnection.java +++ b/opendj-server-legacy/src/main/java/org/opends/server/backends/jdbc/CachedConnection.java @@ -23,11 +23,12 @@ import java.sql.*; import java.time.Duration; +import java.util.ArrayDeque; +import java.util.Deque; import java.util.Locale; import java.util.Map; import java.util.Properties; import java.util.concurrent.*; -import java.util.concurrent.atomic.AtomicBoolean; import java.util.concurrent.atomic.AtomicLong; public class CachedConnection implements Connection { @@ -47,16 +48,26 @@ public class CachedConnection implements Connection { /** Bound of the validation of a pooled connection: isValid(0) means "no timeout" in the JDBC contract. */ static final int VALIDATION_TIMEOUT_SECONDS = 5; + /** 53300, too_many_connections: how the standard - and postgresql - reports a server taking no further connection. */ + private static final String CONNECTION_LIMIT_SQL_STATE = "53300"; + /** 57P03, cannot_connect_now: postgresql starting up, shutting down or in recovery. */ + private static final String NOT_ACCEPTING_YET_SQL_STATE = "57P03"; + static final long MAX_BACKOFF_MS = 1000; static final long STALL_WARNING_AFTER_MS = 1000; static final long STALL_WARNING_INTERVAL_MS = 10000; + /** How many links of the cause and getNextException() chains of a failure are looked at. */ + private static final int MAX_CHAIN_LENGTH = 32; + // setNetworkTimeout() takes the executor its timeout handling runs on: the drivers it is used // with here only set a socket option in it, so it costs a call rather than a thread. private static final Executor DIRECT_EXECUTOR = Runnable::run; - private static final AtomicLong lastStallWarning = new AtomicLong(); - private static final AtomicBoolean readBoundWarned = new AtomicBoolean(); + // Throttled per connection string: two JDBC backends stalling at once have a stall of their + // own to report, and a single timestamp would let one of them starve the other. + private static final Map lastStallWarning = new ConcurrentHashMap<>(); + private static final AtomicLong lastReadBoundWarning = new AtomicLong(); final Connection parent; @@ -80,14 +91,15 @@ public class CachedConnection implements Connection { * {@value #TTL_PROPERTY} system property. An invalid value is ignored in favor of the default. */ private static long getCacheTtlMillis() { - return getNonNegativeProperty(TTL_PROPERTY, DEFAULT_TTL_MS); + return getNonNegativeProperty(TTL_PROPERTY, DEFAULT_TTL_MS, "ms"); } /** * Returns the value of a numeric system property, ignoring a value that is not a non-negative - * number in favor of the default. + * number in favor of the default. The unit is the one the property is read in, so that the + * value the message names is not mistaken for another. */ - private static long getNonNegativeProperty(String name, long defaultValue) { + private static long getNonNegativeProperty(String name, long defaultValue, String unit) { final String value = System.getProperty(name); if (value != null) { try { @@ -97,8 +109,8 @@ private static long getNonNegativeProperty(String name, long defaultValue) { } } catch (NumberFormatException ignored) { } - logger.warn(LocalizableMessage.raw("Ignoring invalid value \"%s\" of the %s property, using %d", - value, name, defaultValue)); + logger.warn(LocalizableMessage.raw("Ignoring invalid value \"%s\" of the %s property, using %d %s", + value, name, defaultValue, unit)); } return defaultValue; } @@ -115,35 +127,71 @@ private static long getNonNegativeProperty(String name, long defaultValue) { */ enum ConnectDialect { /** postgresql: both properties take seconds; loginTimeout bounds the login the driver runs on a thread of its own. */ - POSTGRES("jdbc:postgresql:", "connectTimeout", 1, "loginTimeout", 1, false, new int[]{}), + POSTGRES("jdbc:postgresql:", '?', + "connectTimeout", 1, 0, + new String[]{"loginTimeout"}, 1, false, + new int[]{}, new int[]{}), /** mysql: both properties take milliseconds; socketTimeout is a socket read timeout that outlives the login. */ - MYSQL("jdbc:mysql:", "connectTimeout", 1000, "socketTimeout", 1000, true, new int[]{1040, 1203}), + MYSQL("jdbc:mysql:", '?', + "connectTimeout", 1000, 0, + new String[]{"socketTimeout"}, 1000, true, + new int[]{1040, 1203}, new int[]{1053}), /** oracle: both properties take milliseconds; ReadTimeout is a socket read timeout that outlives the login. */ - ORACLE("jdbc:oracle:", "oracle.net.CONNECT_TIMEOUT", 1000, "oracle.jdbc.ReadTimeout", 1000, true, - new int[]{20, 12516, 12518, 12519, 12520}), - /** ms sql server: loginTimeout takes seconds, socketTimeout milliseconds; the latter is a socket read timeout that outlives the login. */ - MICROSOFT("jdbc:sqlserver:", "loginTimeout", 1, "socketTimeout", 1000, true, new int[]{17809, 10928, 10929}); + ORACLE("jdbc:oracle:", '?', + "oracle.net.CONNECT_TIMEOUT", 1000, 0, + // the read bound goes by three names: the property set here, the property of oracle + // net it stands for, and RECV_TIMEOUT inside a tns descriptor. A bound under any of + // them is a bound of the administrator, so ours is not set on top of it - and none of + // theirs is lifted with ours once the login is through. + new String[]{"oracle.jdbc.ReadTimeout", "oracle.net.READ_TIMEOUT", "RECV_TIMEOUT"}, 1000, true, + // ORA-01033 and ORA-01034: the instance is starting up or not there yet; ORA-01089: + // it is shutting down. ORA-12514 is left out of these on purpose - a listener that + // does not know the service is also what a service name of a typo looks like, forever + new int[]{20, 12516, 12518, 12519, 12520}, new int[]{1033, 1034, 1089}), + /** + * ms sql server: loginTimeout takes seconds, socketTimeout milliseconds; the latter is a + * socket read timeout that outlives the login. loginTimeout is the one property of the + * four with a range of its own - SQLServerDriverIntProperty.LOGIN_TIMEOUT is validated + * against [0, 65535], and a value beyond it fails every connect the driver is asked for. + */ + MICROSOFT("jdbc:sqlserver:", ';', + "loginTimeout", 1, 65535, + new String[]{"socketTimeout"}, 1000, true, + // 921 and 922: the database has not been recovered yet, or is being recovered; 927: it + // is in the middle of a restore; 40613: azure sql reporting it not available for now + new int[]{17809, 10928, 10929}, new int[]{921, 922, 927, 40613}); final String urlPrefix; + /** the character that separates the parameters of this dialect from the url in front of them */ + final char parameterSeparator; final String connectProperty; final int connectUnitsPerSecond; - final String readProperty; + /** the largest value the driver accepts for its connect property, 0 for a driver that takes any */ + final long maxConnectSeconds; + /** the read bound of the login: the first name is the one set here, the rest are the names it also goes by */ + final String[] readProperties; final int readUnitsPerSecond; /** whether the read bound of the login stays in force for every statement issued afterwards */ final boolean readBoundOutlivesLogin; /** the vendor codes of this dialect for "no further connection is accepted" */ final int[] connectionLimitCodes; + /** the vendor codes of this dialect for "not accepting connections yet": a database on its way up */ + final int[] notAcceptingYetCodes; - ConnectDialect(String urlPrefix, String connectProperty, int connectUnitsPerSecond, - String readProperty, int readUnitsPerSecond, boolean readBoundOutlivesLogin, - int[] connectionLimitCodes) { + ConnectDialect(String urlPrefix, char parameterSeparator, + String connectProperty, int connectUnitsPerSecond, long maxConnectSeconds, + String[] readProperties, int readUnitsPerSecond, boolean readBoundOutlivesLogin, + int[] connectionLimitCodes, int[] notAcceptingYetCodes) { this.urlPrefix = urlPrefix; + this.parameterSeparator = parameterSeparator; this.connectProperty = connectProperty; this.connectUnitsPerSecond = connectUnitsPerSecond; - this.readProperty = readProperty; + this.maxConnectSeconds = maxConnectSeconds; + this.readProperties = readProperties; this.readUnitsPerSecond = readUnitsPerSecond; this.readBoundOutlivesLogin = readBoundOutlivesLogin; this.connectionLimitCodes = connectionLimitCodes; + this.notAcceptingYetCodes = notAcceptingYetCodes; } /** The dialect of a connection string, or null for a driver whose property names are not known here. */ @@ -161,45 +209,65 @@ static ConnectDialect of(String connectionString) { * Fills in the properties bounding one connect attempt, leaving out every property the * connection string sets itself - an explicit setting of the administrator keeps * precedence, and the SQL Server driver gives a supplied property precedence over the url. + * A driver with a range of its own for its connect property is not handed a value beyond + * it: a bound it rejects is no bound at all, it is a connect that never happens. * Returns whether a read bound outliving the login was set and has to be lifted once the * connection is established. */ boolean bound(String connectionString, Properties properties, long timeoutSeconds) { if (!declaredInUrl(connectionString, connectProperty)) { - properties.setProperty(connectProperty, Long.toString(timeoutSeconds * connectUnitsPerSecond)); + final long connectSeconds = maxConnectSeconds > 0 + ? Math.min(timeoutSeconds, maxConnectSeconds) : timeoutSeconds; + properties.setProperty(connectProperty, Long.toString(connectSeconds * connectUnitsPerSecond)); } - if (readProperty != null && !declaredInUrl(connectionString, readProperty)) { - properties.setProperty(readProperty, Long.toString(timeoutSeconds * readUnitsPerSecond)); + if (!declaredInUrl(connectionString, readProperties)) { + properties.setProperty(readProperties[0], Long.toString(timeoutSeconds * readUnitsPerSecond)); return readBoundOutlivesLogin; } return false; } - boolean isConnectionLimit(SQLException e) { - for (final int code : connectionLimitCodes) { - if (e.getErrorCode() == code) { + /** Whether a vendor code of this dialect is one that waiting for the database can clear. */ + boolean isWorthRetrying(int errorCode) { + return contains(connectionLimitCodes, errorCode) || contains(notAcceptingYetCodes, errorCode); + } + + private static boolean contains(int[] codes, int code) { + for (final int candidate : codes) { + if (candidate == code) { return true; } } return false; } - // Whether the connection string sets this property itself. The dialects separate their - // parameters differently - "?a=1&b=2" (postgresql, mysql), ";a=1;b=2" (sql server), + // Whether the connection string sets one of these properties itself. The dialects separate + // their parameters differently - "?a=1&b=2" (postgresql, mysql), ";a=1;b=2" (sql server), // "(A=1)" inside the descriptor of an oracle tns url, where the property also goes by the // last segment of its name alone - so a parameter is recognized by the delimiter in front // of it and the "=" behind it rather than by parsing the url syntax of every driver. - private static boolean declaredInUrl(String connectionString, String property) { - if (containsParameter(connectionString, property)) { - return true; + private boolean declaredInUrl(String connectionString, String... properties) { + for (final String property : properties) { + if (containsParameter(connectionString, property)) { + return true; + } + final int dot = property.lastIndexOf('.'); + if (dot >= 0 && containsParameter(connectionString, property.substring(dot + 1))) { + return true; + } } - final int dot = property.lastIndexOf('.'); - return dot >= 0 && containsParameter(connectionString, property.substring(dot + 1)); + return false; } - private static boolean containsParameter(String connectionString, String property) { - final String url = connectionString.toLowerCase(Locale.ROOT); - final String name = property.toLowerCase(Locale.ROOT); + // Matched the way the driver of this dialect matches it: pgjdbc keeps the name of a url + // parameter as it stands and looks its properties up by their exact name, so "?LoginTimeout=" + // is a parameter of nobody and must not be taken for a bound of the administrator - while + // Connector/J (PropertyKey.fromValue), the SQL Server driver (getNormalizedPropertyName) + // and the keywords of an oracle descriptor all match without regard to case. + private boolean containsParameter(String connectionString, String property) { + final boolean exact = this == POSTGRES; + final String url = exact ? connectionString : connectionString.toLowerCase(Locale.ROOT); + final String name = exact ? property : property.toLowerCase(Locale.ROOT); for (int i = url.indexOf(name); i >= 0; i = url.indexOf(name, i + name.length())) { final int end = i + name.length(); if (i > 0 && "?&;(,".indexOf(url.charAt(i - 1)) >= 0 && end < url.length() && url.charAt(end) == '=') { @@ -225,8 +293,9 @@ public CachedConnection(String connectionString, Connection parent) { static Connection getConnection(String connectionString) throws Exception { final ConnectDialect dialect = ConnectDialect.of(connectionString); final long connectTimeoutSeconds = Math.min( - getNonNegativeProperty(CONNECT_TIMEOUT_PROPERTY, DEFAULT_CONNECT_TIMEOUT_SECONDS), Integer.MAX_VALUE / 1000); - final long poolTimeoutSeconds = getNonNegativeProperty(POOL_TIMEOUT_PROPERTY, DEFAULT_POOL_TIMEOUT_SECONDS); + getNonNegativeProperty(CONNECT_TIMEOUT_PROPERTY, DEFAULT_CONNECT_TIMEOUT_SECONDS, "s"), + Integer.MAX_VALUE / 1000); + final long poolTimeoutSeconds = getNonNegativeProperty(POOL_TIMEOUT_PROPERTY, DEFAULT_POOL_TIMEOUT_SECONDS, "s"); final long startedAt = System.currentTimeMillis(); final long deadline = (poolTimeoutSeconds == 0 || poolTimeoutSeconds >= Long.MAX_VALUE / 1000) ? Long.MAX_VALUE : startedAt + poolTimeoutSeconds * 1000; @@ -234,25 +303,27 @@ static Connection getConnection(String connectionString) throws Exception { long backoffMs = 0; int attempts = 0; while (true) { - final CachedConnection pooled = poll(connectionString, waitMs); + final CachedConnection pooled = poll(connectionString, waitMs, deadline); if (pooled != null) { return pooled; } attempts++; try { - return connect(connectionString, dialect, connectTimeoutSeconds); + return connect(connectionString, dialect, attemptSeconds(connectTimeoutSeconds, deadline)); } catch (SQLException e) { - // A database that accepts no further connection is the one failure worth waiting - // out: one of ours is going to come back to the pool. Everything else - a password - // that is not accepted, a database that is down, a driver that is not on the - // classpath - is reported to the caller instead of being retried behind its back. - if (!isConnectionLimit(e, dialect)) { + // A database that takes no connection for the moment is the failure worth waiting + // out: it is at its connection limit, and one of ours is going to come back to the + // pool - or it is on its way up, and the state clears itself in seconds. Everything + // else - a password that is not accepted, a database that is down, a driver that is + // not on the classpath - is reported to the caller instead of being retried behind + // its back. + if (!isWorthRetrying(e, dialect)) { throw e; } final long remaining = deadline - System.currentTimeMillis(); if (remaining <= 0) { throw new SQLTimeoutException("no connection to " + safeUrl(connectionString) + " could be borrowed within " - + poolTimeoutSeconds + "s (" + attempts + " attempts): the database accepts no further connection" + + poolTimeoutSeconds + "s (" + attempts + " attempts): the database took no further connection" + " and none was returned to the pool", e); } backoffMs = Math.min(backoffMs == 0 ? 1 : backoffMs * 2, MAX_BACKOFF_MS); @@ -262,10 +333,33 @@ static Connection getConnection(String connectionString) throws Exception { } } - /** Takes a usable connection out of the pool, waiting up to waitMs for one to be returned to it. */ - private static CachedConnection poll(String connectionString, long waitMs) throws InterruptedException { + /** + * The bound of one connect attempt. The deadline of the borrow bounds it as well - the + * {@value #POOL_TIMEOUT_PROPERTY} property stands for the whole borrow, and an attempt of its + * own left to run out would overrun it by a full connect timeout. Never 0 for an attempt that + * is bounded at all: 0 is the value that stands for no bound. + */ + private static long attemptSeconds(long connectTimeoutSeconds, long deadline) { + if (connectTimeoutSeconds == 0 || deadline == Long.MAX_VALUE) { + return connectTimeoutSeconds; + } + final long remainingSeconds = (deadline - System.currentTimeMillis() + 999) / 1000; + return Math.max(1, Math.min(connectTimeoutSeconds, remainingSeconds)); + } + + /** + * Takes a usable connection out of the pool, waiting up to waitMs for one to be returned to it. + * The validation of a connection costs a round trip, and the pool has no upper bound on the + * number of them it holds, so draining a pool the database no longer answers is given the + * deadline of the borrow as well: past it, establishing a connection is the faster answer. + */ + private static CachedConnection poll(String connectionString, long waitMs, long deadline) throws InterruptedException { CachedConnection con = cached.get(connectionString).poll(waitMs, TimeUnit.MILLISECONDS); while (con != null) { + if (System.currentTimeMillis() >= deadline) { + closeQuietly(con.parent); + return null; + } if (isUsable(con)) { return con; } @@ -276,13 +370,42 @@ private static CachedConnection poll(String connectionString, long waitMs) throw } private static boolean isUsable(CachedConnection con) { + // The validation needs a bound of its own: isValid(0) means "no timeout" in the JDBC + // contract, and a connection whose socket is half-open answers it no sooner than it + // answers anything else. isValid(n) is not that bound on every driver either - the SQL + // Server driver turns it into a query timeout (setQueryTimeout, then "SELECT 1"), which + // needs an answer from the server to fire at all - so the socket is bounded here, for the + // validation only. + final int restore = boundValidation(con.parent); + boolean usable; try { - // The validation needs a bound of its own: isValid(0) means "no timeout" in the JDBC - // contract, and a connection whose socket is half-open answers it no sooner than it - // answers anything else. - return con.isValid(VALIDATION_TIMEOUT_SECONDS); + usable = con.isValid(VALIDATION_TIMEOUT_SECONDS); } catch (SQLException e) { // a driver reporting the validation as an error: discard it - return false; + usable = false; + } + if (restore >= 0 && !setNetworkTimeout(con.parent, restore)) { + return false; // it would carry the bound of the validation into every statement + } + return usable; + } + + /** + * Bounds the socket of a pooled connection for the length of its validation, returning the + * network timeout to put back afterwards - or -1 for a connection left alone, either because + * the driver does not take one or because it is bounded at least as tightly already, by a read + * timeout of the connection string that is not ours to widen. + */ + private static int boundValidation(Connection con) { + final int bound = VALIDATION_TIMEOUT_SECONDS * 1000; + try { + final int previous = con.getNetworkTimeout(); + if (previous > 0 && previous <= bound) { + return -1; + } + con.setNetworkTimeout(DIRECT_EXECUTOR, bound); + return previous; + } catch (SQLException | RuntimeException e) { + return -1; } } @@ -300,7 +423,7 @@ private static CachedConnection connect(String connectionString, ConnectDialect if (readBoundSet) { relaxReadBound(conNew); } - } catch (SQLException e) { // nothing holds this connection yet: it would leak + } catch (SQLException | RuntimeException e) { // nothing holds this connection yet: it would leak closeQuietly(conNew); throw e; } @@ -314,29 +437,58 @@ private static CachedConnection connect(String connectionString, ConnectDialect // established before. A read bound the connection string sets itself is never touched here: // it is not set at all, so nothing of the administrator's is lifted along with it. private static void relaxReadBound(Connection con) { + setNetworkTimeout(con, 0); + } + + /** Puts a network timeout on a connection, reporting a driver that will not take one. */ + private static boolean setNetworkTimeout(Connection con, int millis) { try { - con.setNetworkTimeout(DIRECT_EXECUTOR, 0); + con.setNetworkTimeout(DIRECT_EXECUTOR, millis); + return true; } catch (SQLException | RuntimeException e) { - if (readBoundWarned.compareAndSet(false, true)) { + // Throttled rather than reported once for the life of the JVM: every connection this + // happens to carries a read bound it was never meant to keep, and a statement dying of + // it hours later needs a warning of its own to be traced back to here. + final long now = System.currentTimeMillis(); + final long last = lastReadBoundWarning.get(); + if (now - last >= STALL_WARNING_INTERVAL_MS && lastReadBoundWarning.compareAndSet(last, now)) { logger.warn(LocalizableMessage.raw( - "The read bound of the login could not be lifted (%s): statements taking longer than the %s" - + " property will fail on connections of this backend", e.getMessage(), CONNECT_TIMEOUT_PROPERTY)); + "The read bound of a JDBC connection could not be set to %d ms (%s): statements taking longer" + + " than the %s property may fail on connections of this backend", + millis, e.getMessage(), CONNECT_TIMEOUT_PROPERTY)); } + return false; } } - /** Whether the database refused the connection because it accepts no further one. */ - static boolean isConnectionLimit(SQLException e, ConnectDialect dialect) { - for (Throwable t = e; t != null; t = t.getCause()) { + /** + * Whether the database took no connection for the moment, rather than refusing one for good: + * it is at its connection limit - one of our own connections is on its way back to the pool - + * or it is not accepting connections yet, the state a database on its way up reports while it + * recovers - the one JDBCStorage.open() has no second attempt of its own for, so a backend + * that meets it stays locked down until the server is restarted. Both clear themselves in + * seconds; every other failure is the caller's to see. + */ + static boolean isWorthRetrying(SQLException e, ConnectDialect dialect) { + // a failure of the driver is often wrapped, and a SQLException carries two chains of its + // own: the causes behind it and the further exceptions of getNextException() + final Deque pending = new ArrayDeque<>(); + pending.add(e); + for (int visited = 0; !pending.isEmpty() && visited < MAX_CHAIN_LENGTH; visited++) { + final Throwable t = pending.poll(); if (t instanceof SQLException) { final SQLException sql = (SQLException) t; - // class 53, insufficient_resources, is how the standard - and postgresql, with - // 53300 too_many_connections - reports a server taking no further connection final String sqlState = sql.getSQLState(); - if ((sqlState != null && sqlState.startsWith("53")) - || (dialect != null && dialect.isConnectionLimit(sql))) { + if (CONNECTION_LIMIT_SQL_STATE.equals(sqlState) || NOT_ACCEPTING_YET_SQL_STATE.equals(sqlState) + || (dialect != null && dialect.isWorthRetrying(sql.getErrorCode()))) { return true; } + if (sql.getNextException() != null) { + pending.add(sql.getNextException()); + } + } + if (t.getCause() != null) { + pending.add(t.getCause()); } } return false; @@ -350,34 +502,50 @@ private static void warnStall(String connectionString, int attempts, long starte if (now - startedAt < STALL_WARNING_AFTER_MS) { return; } - final long last = lastStallWarning.get(); - if (now - last >= STALL_WARNING_INTERVAL_MS && lastStallWarning.compareAndSet(last, now)) { + final AtomicLong lastOfThisUrl = lastStallWarning.computeIfAbsent(connectionString, url -> new AtomicLong()); + final long last = lastOfThisUrl.get(); + if (now - last >= STALL_WARNING_INTERVAL_MS && lastOfThisUrl.compareAndSet(last, now)) { logger.warn(LocalizableMessage.raw( - "%s accepts no further connection: waiting %d ms for a pooled one so far (%d attempts), last error: %s", + "%s takes no further connection: waiting %d ms for a pooled one so far (%d attempts), last error: %s", safeUrl(connectionString), now - startedAt, attempts, cause.getMessage())); } } // The connection string carries the credentials of the backend, so it is never logged as it - // stands. Parameters - "?user=...&password=..." on postgresql and mysql, ";password=..." on - // sql server - are cut off behind their first separator, while the credentials of a url that - // carries them in front of an "@" ("user/password@//host" on an oracle thin url, the userinfo - // of a url) are cut off in front of it, leaving the scheme and the host they stand between. + // stands. The credentials of a url that carries them in front of an "@" ("user/password@//host" + // on an oracle thin url, the userinfo of a url) are cut off in front of it, leaving the scheme + // and the host they stand between; parameters - "?user=...&password=..." on postgresql, mysql + // and oracle, ";password=..." on sql server - are cut off behind their first separator. + // + // The order of the two is what a password holding a separator of another dialect turns on: the + // ";" of "scott/pa;ss@//host" is a separator on sql server and nothing on oracle, so the + // separator is taken from the dialect of the url, and the userinfo goes first where it stands + // in front of the parameters. static String safeUrl(String connectionString) { - int cut = connectionString.length(); - for (final char separator : new char[]{'?', ';'}) { - final int at = connectionString.indexOf(separator); - if (at >= 0 && at < cut) { - cut = at; + final ConnectDialect dialect = ConnectDialect.of(connectionString); + final String separators = dialect == null ? "?;" : String.valueOf(dialect.parameterSeparator); + String url = connectionString; + final int at = url.indexOf('@'); + final int firstParameter = indexOfAny(url, separators); + if (at >= 0 && (firstParameter < 0 || at < firstParameter)) { + final int scheme = url.indexOf(':', "jdbc:".length()) + 1; // the end of "jdbc::" + if (scheme > 0 && scheme < at) { + url = url.substring(0, scheme) + url.substring(at); } } - final String url = connectionString.substring(0, cut); - final int at = url.indexOf('@'); - if (at < 0) { - return url; + final int cut = indexOfAny(url, separators); + return cut < 0 ? url : url.substring(0, cut); + } + + private static int indexOfAny(String url, String separators) { + int found = -1; + for (int i = 0; i < separators.length(); i++) { + final int at = url.indexOf(separators.charAt(i)); + if (at >= 0 && (found < 0 || at < found)) { + found = at; + } } - final int scheme = url.indexOf(':', "jdbc:".length()) + 1; // the end of "jdbc::" - return url.substring(0, scheme) + url.substring(at); + return found; } private static void closeQuietly(Connection con) { diff --git a/opendj-server-legacy/src/test/java/org/opends/server/backends/jdbc/CachedConnectionTestCase.java b/opendj-server-legacy/src/test/java/org/opends/server/backends/jdbc/CachedConnectionTestCase.java index 1590536363..9d3584194a 100644 --- a/opendj-server-legacy/src/test/java/org/opends/server/backends/jdbc/CachedConnectionTestCase.java +++ b/opendj-server-legacy/src/test/java/org/opends/server/backends/jdbc/CachedConnectionTestCase.java @@ -31,14 +31,20 @@ import java.sql.SQLTimeoutException; import java.util.Properties; import java.util.concurrent.ExecutionException; +import java.util.concurrent.Executor; import java.util.concurrent.FutureTask; import java.util.concurrent.TimeUnit; import java.util.concurrent.TimeoutException; import java.util.concurrent.atomic.AtomicInteger; import java.util.logging.Logger; +import org.mockito.InOrder; + +import static org.mockito.Mockito.any; import static org.mockito.Mockito.anyInt; import static org.mockito.Mockito.doThrow; +import static org.mockito.Mockito.eq; +import static org.mockito.Mockito.inOrder; import static org.mockito.Mockito.mock; import static org.mockito.Mockito.never; import static org.mockito.Mockito.verify; @@ -151,6 +157,28 @@ public void testLoginIsBoundedWhenTheDatabaseNeverAnswers() throws Exception { } } + /** + * The deadline of the borrow bounds the attempt inside it as well: the pool timeout stands for + * the whole borrow, and an attempt left to run out its own bound would overrun it by that bound. + */ + @Test(timeOut = 120000) + public void testTheAttemptIsBoundedByTheDeadlineOfTheBorrow() throws Exception { + System.setProperty(CachedConnection.CONNECT_TIMEOUT_PROPERTY, "600"); + System.setProperty(CachedConnection.POOL_TIMEOUT_PROPERTY, "2"); + try (final ServerSocket blackhole = new ServerSocket(0, 50, InetAddress.getLoopbackAddress())) { + final String url = "jdbc:postgresql://127.0.0.1:" + blackhole.getLocalPort() + "/opendj?user=opendj&password=opendj"; + final long startedAt = System.currentTimeMillis(); + try { + CachedConnection.getConnection(url); + fail("a database that never answers must not hand out a connection"); + } catch (SQLException expected) { + // reported, and within the borrow it was given rather than the 600 s of the attempt + } + final long elapsed = System.currentTimeMillis() - startedAt; + assertTrue(elapsed < 30000, "the attempt outlived the deadline of the borrow: " + elapsed + " ms"); + } + } + /** Pool exhaustion stays a retry - one of our own connections is on its way back to the pool. */ @Test(timeOut = 120000) public void testConnectionLimitIsRetried() throws Exception { @@ -185,6 +213,55 @@ public void testConnectionLimitGivesUpAtTheDeadline() throws Exception { assertTrue(stub.attempts.get() > 1, "the connect must be retried while the deadline lasts"); } + /** + * A database on its way up - starting, recovering, shutting down - says so, and says it for + * seconds: the backend it belongs to would otherwise stay locked down until the next restart + * of the server, since nothing above JDBCStorage.open() attempts it a second time. + */ + @Test(timeOut = 120000) + public void testDatabaseOnItsWayUpIsRetried() throws Exception { + final String url = StubDriver.PREFIX + "starting-up"; + stub.failWith(new SQLException("the database system is starting up", "57P03"), 2); + System.setProperty(CachedConnection.POOL_TIMEOUT_PROPERTY, "30"); + + final Connection con = CachedConnection.getConnection(url); + + assertNotNull(con); + assertEquals(stub.attempts.get(), 3, "a database that is starting up must be waited out"); + } + + /** ... and it is recognized however the driver wrapped it: a SQLException carries two chains. */ + @Test(timeOut = 120000) + public void testTheWholeChainOfTheFailureIsLookedAt() throws Exception { + final String url = StubDriver.PREFIX + "wrapped"; + final SQLException wrapped = new SQLException("could not connect to the server", "08006"); + wrapped.setNextException(tooManyConnections()); + stub.failWith(wrapped, 1); + System.setProperty(CachedConnection.POOL_TIMEOUT_PROPERTY, "30"); + + assertNotNull(CachedConnection.getConnection(url)); + assertEquals(stub.attempts.get(), 2, "the failure behind the one reported must be looked at"); + } + + /** + * The rest of the insufficient_resources class is not worth waiting out: a server out of disk + * is not made whole by a connection of ours coming back to the pool. + */ + @Test(timeOut = 120000) + public void testDiskFullIsNotRetried() throws Exception { + final String url = StubDriver.PREFIX + "disk-full"; + stub.failWith(new SQLException("could not extend file: No space left on device", "53100"), StubDriver.ALWAYS); + System.setProperty(CachedConnection.POOL_TIMEOUT_PROPERTY, "30"); + + try { + CachedConnection.getConnection(url); + fail("a database out of disk must be reported to the caller"); + } catch (SQLException expected) { + assertEquals(expected.getSQLState(), "53100"); + } + assertEquals(stub.attempts.get(), 1, "a failure that waiting cannot clear must be attempted once"); + } + /** * Every other failure is the caller's to report. A password the database does not accept is * never going to be accepted by waiting, and the retry that swallowed it left the operation @@ -222,6 +299,90 @@ public void testConnectionIsClosedWhenItsSetupFails() throws Exception { verify(broken).close(); } + /** The same, for a driver whose failure in the setup is not a SQLException but an unchecked one. */ + @Test(timeOut = 120000) + public void testConnectionIsClosedWhenItsSetupFailsWithAnUncheckedError() throws Exception { + final String url = StubDriver.PREFIX + "setup-unchecked"; + final Connection broken = mock(Connection.class); + doThrow(new IllegalStateException("driver internal")).when(broken).setTransactionIsolation(anyInt()); + stub.answerWith(broken); + + try { + CachedConnection.getConnection(url); + fail("a connection that cannot be set up must be reported"); + } catch (IllegalStateException expected) { + assertEquals(expected.getMessage(), "driver internal"); + } + verify(broken).close(); + } + + /** + * isValid(n) is not a bound at the socket on every driver - the SQL Server driver turns it + * into a query timeout, which needs an answer from the server to fire - and the read bound of + * the login was lifted the moment the connection was established, so the socket carries the + * bound of the validation, for the length of the validation only. + */ + @Test(timeOut = 120000) + public void testValidationOfAPooledConnectionIsBoundedAtTheSocket() throws Exception { + final String url = StubDriver.PREFIX + "validation-bound"; + final Connection pooled = mock(Connection.class); + when(pooled.isValid(anyInt())).thenReturn(true); + when(pooled.getNetworkTimeout()).thenReturn(0); + CachedConnection.cached.get(url).add(new CachedConnection(url, pooled)); + + final Connection borrowed = CachedConnection.getConnection(url); + + assertSame(((CachedConnection) borrowed).parent, pooled); + final InOrder inOrder = inOrder(pooled); + inOrder.verify(pooled).setNetworkTimeout(any(Executor.class), eq(CachedConnection.VALIDATION_TIMEOUT_SECONDS * 1000)); + inOrder.verify(pooled).isValid(CachedConnection.VALIDATION_TIMEOUT_SECONDS); + inOrder.verify(pooled).setNetworkTimeout(any(Executor.class), eq(0)); + } + + /** A read bound of the connection string is tighter than ours and stays untouched. */ + @Test(timeOut = 120000) + public void testValidationLeavesTheBoundOfTheConnectionStringAlone() throws Exception { + final String url = StubDriver.PREFIX + "validation-tighter"; + final Connection pooled = mock(Connection.class); + when(pooled.isValid(anyInt())).thenReturn(true); + when(pooled.getNetworkTimeout()).thenReturn(2000); + CachedConnection.cached.get(url).add(new CachedConnection(url, pooled)); + + assertNotNull(CachedConnection.getConnection(url)); + + verify(pooled, never()).setNetworkTimeout(any(Executor.class), anyInt()); + } + + /** + * The pool has no upper bound on the number of connections it holds, and a validation is a + * round trip: after a failover that left them half-open, draining the pool must not outlive + * the deadline of the borrow - establishing a connection is the faster answer past it. + */ + @Test(timeOut = 120000) + public void testDrainOfThePoolStopsAtTheDeadline() throws Exception { + final String url = StubDriver.PREFIX + "drain-deadline"; + final int pooled = 8; + final AtomicInteger validated = new AtomicInteger(); + for (int i = 0; i < pooled; i++) { + final Connection stale = mock(Connection.class); + when(stale.isValid(anyInt())).thenAnswer(invocation -> { + validated.incrementAndGet(); + Thread.sleep(500); // a database that no longer answers: every validation waits out its bound + return false; + }); + CachedConnection.cached.get(url).add(new CachedConnection(url, stale)); + } + final Connection fresh = mock(Connection.class); + stub.answerWith(fresh); + System.setProperty(CachedConnection.POOL_TIMEOUT_PROPERTY, "1"); + + final Connection borrowed = CachedConnection.getConnection(url); + + assertSame(((CachedConnection) borrowed).parent, fresh); + assertTrue(validated.get() < pooled, + "the whole pool was validated past the deadline: " + validated.get() + " of " + pooled); + } + /** A pooled connection that no longer validates is closed and replaced, not handed out. */ @Test(timeOut = 120000) public void testBrokenPooledConnectionIsDiscarded() throws Exception { @@ -294,6 +455,19 @@ public void testBothPhasesOfTheLoginAreBounded() throws Exception { assertEquals(microsoft.getProperty("socketTimeout"), "7000"); } + /** + * A driver with a range of its own for its connect property is never handed a value beyond it: + * SQLServerDriverIntProperty.LOGIN_TIMEOUT is validated against [0, 65535], so a bound past + * that would not widen the connect, it would fail every one of them. + */ + @Test + public void testConnectBoundStaysInTheRangeTheDriverTakes() throws Exception { + final Properties microsoft = new Properties(); + CachedConnection.ConnectDialect.MICROSOFT.bound("jdbc:sqlserver://h:1433;databaseName=db", microsoft, 100000); + assertEquals(microsoft.getProperty("loginTimeout"), "65535"); + assertEquals(microsoft.getProperty("socketTimeout"), "100000000", "the read bound takes any value"); + } + /** * A bound the administrator put into the connection string by hand - the only workaround this * backend had - keeps precedence, property by property. @@ -319,6 +493,14 @@ public void testConnectionStringKeepsPrecedence() throws Exception { assertNull(oracle.getProperty("oracle.net.CONNECT_TIMEOUT")); assertEquals(oracle.getProperty("oracle.jdbc.ReadTimeout"), "7000"); + // inside the descriptor the read bound goes by RECV_TIMEOUT, and one of the administrator + // is never lifted after the login, because ours is not set on top of it + final Properties recv = new Properties(); + assertFalse(CachedConnection.ConnectDialect.ORACLE.bound( + "jdbc:oracle:thin:@(DESCRIPTION=(RECV_TIMEOUT=30)(ADDRESS=(HOST=h)(PORT=1521)))", recv, 7), + "a read bound of the connection string must not be lifted once the login is through"); + assertNull(recv.getProperty("oracle.jdbc.ReadTimeout")); + // a name that only appears as the tail of another parameter is not a setting of its own final Properties mysql = new Properties(); CachedConnection.ConnectDialect.MYSQL.bound("jdbc:mysql://h:3306/db?xconnectTimeout=1&socketTimeoutX=2", mysql, 7); @@ -326,6 +508,26 @@ public void testConnectionStringKeepsPrecedence() throws Exception { assertEquals(mysql.getProperty("socketTimeout"), "7000"); } + /** + * A parameter is recognized the way the driver of its dialect recognizes it: pgjdbc looks its + * properties up by their exact name, so a name of another case is a parameter of nobody and + * must not pass for a bound the administrator set - while the other three match either way. + */ + @Test + public void testTheCaseOfAParameterIsTheOneOfItsDriver() throws Exception { + final Properties postgres = new Properties(); + CachedConnection.ConnectDialect.POSTGRES.bound("jdbc:postgresql://h:5432/db?ConnectTimeout=5", postgres, 7); + assertEquals(postgres.getProperty("connectTimeout"), "7", "pgjdbc ignores a parameter of another case"); + + final Properties mysql = new Properties(); + CachedConnection.ConnectDialect.MYSQL.bound("jdbc:mysql://h:3306/db?SocketTimeout=1", mysql, 7); + assertNull(mysql.getProperty("socketTimeout"), "Connector/J matches its properties without case"); + + final Properties microsoft = new Properties(); + CachedConnection.ConnectDialect.MICROSOFT.bound("jdbc:sqlserver://h:1433;LoginTimeout=45", microsoft, 7); + assertNull(microsoft.getProperty("loginTimeout"), "the sql server driver normalizes the name of a property"); + } + /** The connection string holds the credentials of the backend: a stall report must not carry them. */ @Test public void testLoggedConnectionStringCarriesNoCredentials() throws Exception { @@ -334,6 +536,12 @@ public void testLoggedConnectionStringCarriesNoCredentials() throws Exception { assertEquals(CachedConnection.safeUrl("jdbc:oracle:thin:scott/secret@//h:1521/svc"), "jdbc:oracle:@//h:1521/svc"); assertEquals(CachedConnection.safeUrl("jdbc:mysql://u:secret@h:3306/db"), "jdbc:mysql:@h:3306/db"); assertEquals(CachedConnection.safeUrl("jdbc:oracle:thin:@//h:1521/svc"), "jdbc:oracle:@//h:1521/svc"); + // a password holding the parameter separator of another dialect: ";" separates nothing on + // an oracle url, so the credentials are cut in front of the "@" rather than inside them + assertEquals(CachedConnection.safeUrl("jdbc:oracle:thin:scott/pa;ss@//h:1521/svc"), "jdbc:oracle:@//h:1521/svc"); + // ... and an "@" that stands inside a parameter is not the end of credentials: the host survives + assertEquals(CachedConnection.safeUrl("jdbc:postgresql://h:5432/db?user=u@example.com&password=secret"), + "jdbc:postgresql://h:5432/db"); } private static SQLException tooManyConnections() { From e77c8f72676294a47ee9db06ded3890e63febf9a Mon Sep 17 00:00:00 2001 From: Valera V Harseko Date: Thu, 20 Aug 2026 12:55:14 +0300 Subject: [PATCH 3/8] [#872] Bound the login of pgjdbc at the socket, and the rest of what the review found open pgjdbc puts an SO_TIMEOUT on the login socket only where socketTimeout is set, and it defaults to none, so every read of the login - the prelogin handshake, TLS, authentication - was left to loginTimeout alone. That one is not a bound of the socket at all: Driver.connect hands the login to a daemon thread of its own and gives up on the thread rather than on the login, leaving it parked in the read for as long as the read lasts. Against the database this change exists for - one that completes the TCP handshake and then says nothing - each borrow to postgresql returned on time and left a daemon thread and an ESTABLISHED socket behind it, where the code before this branch parked the operation thread alone; tcpKeepAlive is off by default, so nothing reaped them. socketTimeout is set now, as on the other three dialects, and lifted once the login is through; loginTimeout is kept on top of it for a url naming more than one host, where each host costs a connect and a login of its own. Also from the review: - the deadline of a borrow stops the drain of the pool rather than destroying the connection in hand: a database at its connection limit has no source of connections other than the ones coming back, and one returned to the pool a moment before the deadline is the connection this borrow was waiting for; - nothing is put back on a connection whose validation failed - Connector/J aborts such a connection and the sql server driver terminates it, so the restore failed as well and warned about the statements of a connection that is being closed, over an idle connection the server had merely reaped; - a connection whose read bound could not be lifted serves the borrower waiting for it and is closed rather than pooled: the result of relaxReadBound() used to be dropped, and the bound of the login went into every borrow the pool handed that connection to - an import batch among them; - the deadline of the borrow bounds a connect attempt even where the ...jdbc.connect.timeout property gives it no bound of its own: turning the per-attempt bound off must not turn the bound of the whole borrow off with it; - safeUrl() looks for the credentials where the url of the dialect holds them - between the subprotocol and the first "@" on oracle, inside the authority elsewhere - so a password holding the parameter separator of its own dialect ("scott/pa?ss@//host") no longer reaches the log; - the message of the timeout no longer reports a database on its way up as one at its connection limit, and carries the last error it saw. CachedConnectionTestCase is at 28 tests, still without a database and ~22 s: the login thread pgjdbc abandons, the pooled connection the deadline used to close unvalidated, the bound that is not put back on a reaped connection, the connection that must not be pooled, and a connect attempt the deadline bounds on its own. Each of them fails against the code it fixes - the last one by hanging for the whole 600 s of the run, which is the shape of #872 itself. --- .../backends/jdbc/CachedConnection.java | 194 +++++++++++++----- .../jdbc/CachedConnectionTestCase.java | 153 +++++++++++++- 2 files changed, 289 insertions(+), 58 deletions(-) diff --git a/opendj-server-legacy/src/main/java/org/opends/server/backends/jdbc/CachedConnection.java b/opendj-server-legacy/src/main/java/org/opends/server/backends/jdbc/CachedConnection.java index a1184bc815..e312d5504b 100644 --- a/opendj-server-legacy/src/main/java/org/opends/server/backends/jdbc/CachedConnection.java +++ b/opendj-server-legacy/src/main/java/org/opends/server/backends/jdbc/CachedConnection.java @@ -37,7 +37,12 @@ public class CachedConnection implements Connection { static final String TTL_PROPERTY = "org.openidentityplatform.opendj.jdbc.ttl"; static final long DEFAULT_TTL_MS = 15000; - /** Bounds the connect and the login of one attempt to establish a connection, in seconds; 0 for no bound. */ + /** + * Bounds the connect and the login of one attempt to establish a connection, in seconds; 0 for + * no bound of its own - the deadline of {@value #POOL_TIMEOUT_PROPERTY} still bounds the + * attempt, since it stands for the whole borrow. Setting both to 0 is what leaves a connect + * unbounded. + */ static final String CONNECT_TIMEOUT_PROPERTY = "org.openidentityplatform.opendj.jdbc.connect.timeout"; static final long DEFAULT_CONNECT_TIMEOUT_SECONDS = 30; @@ -121,24 +126,36 @@ private static long getNonNegativeProperty(String name, long defaultValue, Strin * them bounds the attempt with a single property: the one named first covers the socket * connect, and the login behind it - the reads of the prelogin handshake, of TLS and of * authentication, the phase a proxy at its connection limit or a moved VIP leaves unanswered - - * needs the second. That holds for the SQL Server driver too, whose loginTimeout leaves the - * read of the prelogin answer unbounded (CachedConnectionTestCase covers every one of them - * against a socket that never answers). + * needs the read bound behind it. That holds for the SQL Server driver too, whose loginTimeout + * leaves the read of the prelogin answer unbounded - and for pgjdbc, whose loginTimeout is not + * a bound of the socket at all: Driver.connect hands the login to a daemon thread of its own + * and abandons it at the timeout, so an unbounded read there leaks a thread and a socket per + * borrow instead of failing one (CachedConnectionTestCase covers every one of them against a + * socket that never answers). */ enum ConnectDialect { - /** postgresql: both properties take seconds; loginTimeout bounds the login the driver runs on a thread of its own. */ + /** + * postgresql: every property of the three takes seconds. connectTimeout covers the socket + * connect and socketTimeout the reads of the login: pgjdbc puts an SO_TIMEOUT on the login + * socket only where socketTimeout is set (ConnectionFactoryImpl.openConnectionImpl, both + * before and after enableSSL), and it defaults to none. loginTimeout is kept on top of the + * two for a url naming more than one host, where each of them costs a connect and a login + * of its own - but it is not a bound this class could rely on alone: Driver.connect runs + * the login on a daemon thread, gives up on the thread rather than on the login, and the + * thread stays parked in the read for as long as the read lasts. + */ POSTGRES("jdbc:postgresql:", '?', - "connectTimeout", 1, 0, - new String[]{"loginTimeout"}, 1, false, + new String[]{"connectTimeout", "loginTimeout"}, 1, 0, + new String[]{"socketTimeout"}, 1, true, new int[]{}, new int[]{}), /** mysql: both properties take milliseconds; socketTimeout is a socket read timeout that outlives the login. */ MYSQL("jdbc:mysql:", '?', - "connectTimeout", 1000, 0, + new String[]{"connectTimeout"}, 1000, 0, new String[]{"socketTimeout"}, 1000, true, new int[]{1040, 1203}, new int[]{1053}), /** oracle: both properties take milliseconds; ReadTimeout is a socket read timeout that outlives the login. */ ORACLE("jdbc:oracle:", '?', - "oracle.net.CONNECT_TIMEOUT", 1000, 0, + new String[]{"oracle.net.CONNECT_TIMEOUT"}, 1000, 0, // the read bound goes by three names: the property set here, the property of oracle // net it stands for, and RECV_TIMEOUT inside a tns descriptor. A bound under any of // them is a bound of the administrator, so ours is not set on top of it - and none of @@ -155,7 +172,7 @@ enum ConnectDialect { * against [0, 65535], and a value beyond it fails every connect the driver is asked for. */ MICROSOFT("jdbc:sqlserver:", ';', - "loginTimeout", 1, 65535, + new String[]{"loginTimeout"}, 1, 65535, new String[]{"socketTimeout"}, 1000, true, // 921 and 922: the database has not been recovered yet, or is being recovered; 927: it // is in the middle of a restore; 40613: azure sql reporting it not available for now @@ -164,9 +181,10 @@ enum ConnectDialect { final String urlPrefix; /** the character that separates the parameters of this dialect from the url in front of them */ final char parameterSeparator; - final String connectProperty; + /** the properties bounding the connect: the socket connect, and whatever the driver wraps it in */ + final String[] connectProperties; final int connectUnitsPerSecond; - /** the largest value the driver accepts for its connect property, 0 for a driver that takes any */ + /** the largest value the driver accepts for a connect property, 0 for a driver that takes any */ final long maxConnectSeconds; /** the read bound of the login: the first name is the one set here, the rest are the names it also goes by */ final String[] readProperties; @@ -179,12 +197,12 @@ enum ConnectDialect { final int[] notAcceptingYetCodes; ConnectDialect(String urlPrefix, char parameterSeparator, - String connectProperty, int connectUnitsPerSecond, long maxConnectSeconds, + String[] connectProperties, int connectUnitsPerSecond, long maxConnectSeconds, String[] readProperties, int readUnitsPerSecond, boolean readBoundOutlivesLogin, int[] connectionLimitCodes, int[] notAcceptingYetCodes) { this.urlPrefix = urlPrefix; this.parameterSeparator = parameterSeparator; - this.connectProperty = connectProperty; + this.connectProperties = connectProperties; this.connectUnitsPerSecond = connectUnitsPerSecond; this.maxConnectSeconds = maxConnectSeconds; this.readProperties = readProperties; @@ -215,10 +233,12 @@ static ConnectDialect of(String connectionString) { * connection is established. */ boolean bound(String connectionString, Properties properties, long timeoutSeconds) { - if (!declaredInUrl(connectionString, connectProperty)) { - final long connectSeconds = maxConnectSeconds > 0 - ? Math.min(timeoutSeconds, maxConnectSeconds) : timeoutSeconds; - properties.setProperty(connectProperty, Long.toString(connectSeconds * connectUnitsPerSecond)); + final long connectSeconds = maxConnectSeconds > 0 + ? Math.min(timeoutSeconds, maxConnectSeconds) : timeoutSeconds; + for (final String property : connectProperties) { + if (!declaredInUrl(connectionString, property)) { + properties.setProperty(property, Long.toString(connectSeconds * connectUnitsPerSecond)); + } } if (!declaredInUrl(connectionString, readProperties)) { properties.setProperty(readProperties[0], Long.toString(timeoutSeconds * readUnitsPerSecond)); @@ -279,9 +299,22 @@ private boolean containsParameter(String connectionString, String property) { } final String connectionString; + /** + * Whether this connection may go back into the pool once it is closed. A connection carrying a + * read bound that could not be lifted serves the borrower waiting for it and is closed + * afterwards: left in the pool it would fail every statement slower than that bound - an + * import batch among them - for every borrow the pool hands it to. + */ + private final boolean poolable; + public CachedConnection(String connectionString, Connection parent) { + this(connectionString, parent, true); + } + + CachedConnection(String connectionString, Connection parent, boolean poolable) { this.connectionString = connectionString; this.parent = parent; + this.poolable = poolable; } /** @@ -323,8 +356,8 @@ static Connection getConnection(String connectionString) throws Exception { final long remaining = deadline - System.currentTimeMillis(); if (remaining <= 0) { throw new SQLTimeoutException("no connection to " + safeUrl(connectionString) + " could be borrowed within " - + poolTimeoutSeconds + "s (" + attempts + " attempts): the database took no further connection" - + " and none was returned to the pool", e); + + poolTimeoutSeconds + "s (" + attempts + " attempts): the database took no connection for the" + + " moment and none was returned to the pool, last error: " + e.getMessage(), e); } backoffMs = Math.min(backoffMs == 0 ? 1 : backoffMs * 2, MAX_BACKOFF_MS); waitMs = Math.min(backoffMs, remaining); @@ -336,15 +369,18 @@ static Connection getConnection(String connectionString) throws Exception { /** * The bound of one connect attempt. The deadline of the borrow bounds it as well - the * {@value #POOL_TIMEOUT_PROPERTY} property stands for the whole borrow, and an attempt of its - * own left to run out would overrun it by a full connect timeout. Never 0 for an attempt that - * is bounded at all: 0 is the value that stands for no bound. + * own left to run out would overrun it by a full connect timeout. That holds for an attempt + * the {@value #CONNECT_TIMEOUT_PROPERTY} property gives no bound of its own, too: turning the + * per-attempt bound off must not turn the bound of the borrow off with it. Never 0 for an + * attempt that is bounded at all: 0 is the value that stands for no bound. */ private static long attemptSeconds(long connectTimeoutSeconds, long deadline) { - if (connectTimeoutSeconds == 0 || deadline == Long.MAX_VALUE) { + if (deadline == Long.MAX_VALUE) { return connectTimeoutSeconds; } final long remainingSeconds = (deadline - System.currentTimeMillis() + 999) / 1000; - return Math.max(1, Math.min(connectTimeoutSeconds, remainingSeconds)); + return Math.max(1, connectTimeoutSeconds == 0 + ? remainingSeconds : Math.min(connectTimeoutSeconds, remainingSeconds)); } /** @@ -352,18 +388,21 @@ private static long attemptSeconds(long connectTimeoutSeconds, long deadline) { * The validation of a connection costs a round trip, and the pool has no upper bound on the * number of them it holds, so draining a pool the database no longer answers is given the * deadline of the borrow as well: past it, establishing a connection is the faster answer. + * The connection in hand is always validated first, whatever the deadline says - a database at + * its connection limit has no other source of connections than the ones coming back, and one + * returned to the pool a moment before the deadline is the very connection this borrow waited + * for. Only a connection the database no longer answers is closed here. */ private static CachedConnection poll(String connectionString, long waitMs, long deadline) throws InterruptedException { CachedConnection con = cached.get(connectionString).poll(waitMs, TimeUnit.MILLISECONDS); while (con != null) { - if (System.currentTimeMillis() >= deadline) { - closeQuietly(con.parent); - return null; - } if (isUsable(con)) { return con; } closeQuietly(con.parent); + if (System.currentTimeMillis() >= deadline) { + return null; + } con = cached.get(connectionString).poll(); } return null; @@ -383,10 +422,17 @@ private static boolean isUsable(CachedConnection con) { } catch (SQLException e) { // a driver reporting the validation as an error: discard it usable = false; } + if (!usable) { + // On its way out, and the driver knows it: Connector/J answers a failed validation by + // aborting the connection and the SQL Server driver by terminating it, so putting the + // previous bound back would fail as well - and warn about a bound of a connection that + // is about to be closed, over a reaped idle connection that is nobody's problem. + return false; + } if (restore >= 0 && !setNetworkTimeout(con.parent, restore)) { return false; // it would carry the bound of the validation into every statement } - return usable; + return true; } /** @@ -409,25 +455,29 @@ private static int boundValidation(Connection con) { } } - private static CachedConnection connect(String connectionString, ConnectDialect dialect, long connectTimeoutSeconds) + static CachedConnection connect(String connectionString, ConnectDialect dialect, long connectTimeoutSeconds) throws SQLException { // A driver is free to write into the map it is handed, so it gets one of its own. final Properties properties = new Properties(); final boolean readBoundSet = dialect != null && connectTimeoutSeconds > 0 && dialect.bound(connectionString, properties, connectTimeoutSeconds); final Connection conNew = DriverManager.getConnection(connectionString, properties); + boolean poolable = true; try { // still under the read bound: both of these are round trips of their own conNew.setAutoCommit(false); conNew.setTransactionIsolation(TRANSACTION_READ_COMMITTED); if (readBoundSet) { - relaxReadBound(conNew); + // a driver that will not take the bound back has warned about it already: the + // connection serves the borrower that is waiting for it and is closed rather than + // pooled, so the bound of the login does not outlive it in the pool + poolable = relaxReadBound(conNew); } } catch (SQLException | RuntimeException e) { // nothing holds this connection yet: it would leak closeQuietly(conNew); throw e; } - return new CachedConnection(connectionString, conNew); + return new CachedConnection(connectionString, conNew, poolable); } // The second bound of the login is a socket read timeout on mysql, oracle and sql server, in @@ -435,9 +485,10 @@ private static CachedConnection connect(String connectionString, ConnectDialect // slower than it - an import batch, the statistics of a freshly loaded table - so it is lifted // as soon as the login is through, restoring the behaviour of a connection this class // established before. A read bound the connection string sets itself is never touched here: - // it is not set at all, so nothing of the administrator's is lifted along with it. - private static void relaxReadBound(Connection con) { - setNetworkTimeout(con, 0); + // it is not set at all, so nothing of the administrator's is lifted along with it. Returns + // whether the bound is gone - a connection still carrying it must not be pooled. + private static boolean relaxReadBound(Connection con) { + return setNetworkTimeout(con, 0); } /** Puts a network timeout on a connection, reporting a driver that will not take one. */ @@ -512,35 +563,64 @@ private static void warnStall(String connectionString, int attempts, long starte } // The connection string carries the credentials of the backend, so it is never logged as it - // stands. The credentials of a url that carries them in front of an "@" ("user/password@//host" - // on an oracle thin url, the userinfo of a url) are cut off in front of it, leaving the scheme - // and the host they stand between; parameters - "?user=...&password=..." on postgresql, mysql - // and oracle, ";password=..." on sql server - are cut off behind their first separator. + // stands. The credentials in front of an "@" are cut off - "user/password@//host" on an oracle + // thin url, the userinfo of a url-shaped one - and so are the parameters behind their first + // separator: "?user=...&password=..." on postgresql, mysql and oracle, ";password=..." on sql + // server. // - // The order of the two is what a password holding a separator of another dialect turns on: the - // ";" of "scott/pa;ss@//host" is a separator on sql server and nothing on oracle, so the - // separator is taken from the dialect of the url, and the userinfo goes first where it stands - // in front of the parameters. + // A password is free to hold either of the two delimiters, so neither of them is looked for in + // the whole string. The credentials of an oracle url stand between the subprotocol and the + // first "@", which is the delimiter of its descriptor - a password holding an "@" has to be + // quoted for the driver itself, and a "?" of one is part of the password rather than the start + // of the parameters. Everywhere else they stand inside the authority, between "//" and the + // path behind it, so a "?" of a password is inside them and an "@" of a parameter value + // ("?user=u@example.com") is not mistaken for the end of them: the host survives in the + // message either way. static String safeUrl(String connectionString) { final ConnectDialect dialect = ConnectDialect.of(connectionString); final String separators = dialect == null ? "?;" : String.valueOf(dialect.parameterSeparator); - String url = connectionString; - final int at = url.indexOf('@'); - final int firstParameter = indexOfAny(url, separators); - if (at >= 0 && (firstParameter < 0 || at < firstParameter)) { - final int scheme = url.indexOf(':', "jdbc:".length()) + 1; // the end of "jdbc::" - if (scheme > 0 && scheme < at) { - url = url.substring(0, scheme) + url.substring(at); - } - } - final int cut = indexOfAny(url, separators); + final String url = stripCredentials(connectionString, separators); + final int cut = indexOfAny(url, separators, 0); return cut < 0 ? url : url.substring(0, cut); } - private static int indexOfAny(String url, String separators) { + private static String stripCredentials(String url, String separators) { + final int scheme = url.indexOf(':', "jdbc:".length()) + 1; // the end of "jdbc::" + if (scheme <= 0) { + return url; + } + final boolean authorityShaped = url.startsWith("//", scheme); + final int credentials = authorityShaped ? scheme + 2 : scheme; + final int at = url.indexOf('@', credentials); + if (at < 0 || at >= endOfCredentials(url, credentials, authorityShaped, separators)) { + return url; + } + // the "@" of an oracle url is the delimiter of the descriptor behind it and stays; the one + // of an authority separates the userinfo from the host and goes with the userinfo + return url.substring(0, credentials) + url.substring(authorityShaped ? at + 1 : at); + } + + /** + * Where the credentials of a url of this shape have to end: at the path of an authority - a + * password holds a "?" more readily than a "/" - or at the first parameter of a url that has + * no path. An oracle url has neither, and its first "@" ends them wherever it stands. + */ + private static int endOfCredentials(String url, int credentials, boolean authorityShaped, String separators) { + if (!authorityShaped) { + return url.length(); + } + final int path = url.indexOf('/', credentials); + if (path >= 0) { + return path; + } + final int parameter = indexOfAny(url, separators, credentials); + return parameter < 0 ? url.length() : parameter; + } + + private static int indexOfAny(String url, String separators, int from) { int found = -1; for (int i = 0; i < separators.length(); i++) { - final int at = url.indexOf(separators.charAt(i)); + final int at = url.indexOf(separators.charAt(i), from); if (at >= 0 && (found < 0 || at < found)) { found = at; } @@ -606,6 +686,10 @@ public void close() throws SQLException { closeQuietly(parent); throw e; } + if (!poolable) { + closeQuietly(parent); + return; + } cached.get(connectionString).add(this); } diff --git a/opendj-server-legacy/src/test/java/org/opends/server/backends/jdbc/CachedConnectionTestCase.java b/opendj-server-legacy/src/test/java/org/opends/server/backends/jdbc/CachedConnectionTestCase.java index 9d3584194a..37df742ba9 100644 --- a/opendj-server-legacy/src/test/java/org/opends/server/backends/jdbc/CachedConnectionTestCase.java +++ b/opendj-server-legacy/src/test/java/org/opends/server/backends/jdbc/CachedConnectionTestCase.java @@ -432,10 +432,15 @@ public void testDialectIsRecognizedByTheConnectionString() throws Exception { /** Both phases are bounded, in the units of the driver: the connect alone leaves the login open. */ @Test public void testBothPhasesOfTheLoginAreBounded() throws Exception { + // pgjdbc puts an SO_TIMEOUT on the login socket only where socketTimeout is set: without it + // loginTimeout bounds the caller alone, and the thread the driver runs the login on stays + // parked in the read it abandoned final Properties postgres = new Properties(); - assertFalse(CachedConnection.ConnectDialect.POSTGRES.bound("jdbc:postgresql://h:5432/db", postgres, 7)); + assertTrue(CachedConnection.ConnectDialect.POSTGRES.bound("jdbc:postgresql://h:5432/db", postgres, 7), + "the read bound of postgresql outlives the login and has to be lifted"); assertEquals(postgres.getProperty("connectTimeout"), "7"); - assertEquals(postgres.getProperty("loginTimeout"), "7"); + assertEquals(postgres.getProperty("socketTimeout"), "7"); + assertEquals(postgres.getProperty("loginTimeout"), "7", "the bound of a url naming more than one host"); final Properties mysql = new Properties(); assertTrue(CachedConnection.ConnectDialect.MYSQL.bound("jdbc:mysql://h:3306/db", mysql, 7), @@ -478,6 +483,7 @@ public void testConnectionStringKeepsPrecedence() throws Exception { CachedConnection.ConnectDialect.POSTGRES.bound( "jdbc:postgresql://h:5432/db?user=u&password=p&loginTimeout=30&socketTimeout=300", postgres, 7); assertNull(postgres.getProperty("loginTimeout"), "the setting of the connection string was overridden"); + assertNull(postgres.getProperty("socketTimeout"), "the setting of the connection string was overridden"); assertEquals(postgres.getProperty("connectTimeout"), "7", "the property it leaves open must still be bounded"); // the sql server driver gives a supplied property precedence over the one of the url @@ -534,7 +540,7 @@ public void testLoggedConnectionStringCarriesNoCredentials() throws Exception { assertEquals(CachedConnection.safeUrl("jdbc:postgresql://h:5432/db?user=u&password=secret"), "jdbc:postgresql://h:5432/db"); assertEquals(CachedConnection.safeUrl("jdbc:sqlserver://h:1433;databaseName=db;password=secret"), "jdbc:sqlserver://h:1433"); assertEquals(CachedConnection.safeUrl("jdbc:oracle:thin:scott/secret@//h:1521/svc"), "jdbc:oracle:@//h:1521/svc"); - assertEquals(CachedConnection.safeUrl("jdbc:mysql://u:secret@h:3306/db"), "jdbc:mysql:@h:3306/db"); + assertEquals(CachedConnection.safeUrl("jdbc:mysql://u:secret@h:3306/db"), "jdbc:mysql://h:3306/db"); assertEquals(CachedConnection.safeUrl("jdbc:oracle:thin:@//h:1521/svc"), "jdbc:oracle:@//h:1521/svc"); // a password holding the parameter separator of another dialect: ";" separates nothing on // an oracle url, so the credentials are cut in front of the "@" rather than inside them @@ -542,6 +548,147 @@ public void testLoggedConnectionStringCarriesNoCredentials() throws Exception { // ... and an "@" that stands inside a parameter is not the end of credentials: the host survives assertEquals(CachedConnection.safeUrl("jdbc:postgresql://h:5432/db?user=u@example.com&password=secret"), "jdbc:postgresql://h:5432/db"); + // a password holding the parameter separator of its own dialect: on an oracle url the + // parameters stand behind the descriptor, so a "?" in front of the "@" is part of the + // password and cutting there would leave the start of it in the log + assertEquals(CachedConnection.safeUrl("jdbc:oracle:thin:scott/pa?ss@//h:1521/svc"), "jdbc:oracle:@//h:1521/svc"); + // the same inside an authority, where the credentials end at the path rather than at a "?" + assertEquals(CachedConnection.safeUrl("jdbc:mysql://u:sec?ret@h:3306/db"), "jdbc:mysql://h:3306/db"); + } + + /** + * pgjdbc enforces loginTimeout out of process: Driver.connect hands the login to a daemon + * thread of its own and gives up on the thread rather than on the login. Against the database + * this bound exists for - one that completes the handshake and then says nothing - an + * unbounded read there leaves that thread, and the socket it holds, behind on every borrow; + * a few operations a second are enough to run the server out of threads and file descriptors. + */ + @Test(timeOut = 300000) + public void testTheLoginThreadOfPostgresDoesNotOutliveTheBorrow() throws Exception { + System.setProperty(CachedConnection.CONNECT_TIMEOUT_PROPERTY, Long.toString(BOUND_SECONDS)); + try (final ServerSocket blackhole = new ServerSocket(0, 50, InetAddress.getLoopbackAddress())) { + final String url = "jdbc:postgresql://127.0.0.1:" + blackhole.getLocalPort() + "/opendj?user=opendj&password=opendj"; + try { + CachedConnection.getConnection(url); + fail("a database that never answers must not hand out a connection"); + } catch (SQLException expected) { + // reported to the caller, as the bound of the attempt promises + } + final long giveUpAt = System.currentTimeMillis() + BOUND_SECONDS * 1000 + BOUND_MARGIN_MS; + while (loginThreadsOfPostgres() > 0 && System.currentTimeMillis() < giveUpAt) { + Thread.sleep(100); + } + assertEquals(loginThreadsOfPostgres(), 0, + "the login thread pgjdbc abandoned outlived the borrow: the read of the login is not bounded"); + } + } + + private static int loginThreadsOfPostgres() { + int alive = 0; + for (final Thread thread : Thread.getAllStackTraces().keySet()) { + if (thread.isAlive() && thread.getName().startsWith("PostgreSQL JDBC driver connection thread")) { + alive++; + } + } + return alive; + } + + /** + * The deadline of the borrow stands for the whole borrow, so it bounds the attempt inside it + * even where the per-attempt property gives it no bound of its own: turning that property off + * must not turn the bound of the borrow off with it. + */ + @Test(timeOut = 300000) + public void testTheDeadlineBoundsAnAttemptTheConnectPropertyDoesNot() throws Exception { + System.setProperty(CachedConnection.CONNECT_TIMEOUT_PROPERTY, "0"); + System.setProperty(CachedConnection.POOL_TIMEOUT_PROPERTY, "2"); + try (final ServerSocket blackhole = new ServerSocket(0, 50, InetAddress.getLoopbackAddress())) { + final String url = "jdbc:postgresql://127.0.0.1:" + blackhole.getLocalPort() + "/opendj?user=opendj&password=opendj"; + final long startedAt = System.currentTimeMillis(); + try { + CachedConnection.getConnection(url); + fail("a database that never answers must not hand out a connection"); + } catch (SQLException expected) { + // bounded by what is left of the deadline of the borrow + } + assertElapsedWithinBound(startedAt, 2000); + } + } + + /** + * The deadline stops the drain of the pool; it does not throw away the connection in hand. A + * database at its connection limit has no other source of connections than the ones coming + * back to the pool, and closing one unvalidated takes it out of that source for good - while + * the borrow that closed it fails with a timeout anyway. + */ + @Test(timeOut = 120000) + public void testAPooledConnectionIsNotDiscardedUnvalidatedAtTheDeadline() throws Exception { + final String url = StubDriver.PREFIX + "unvalidated-at-deadline"; + final Connection stale = mock(Connection.class); + when(stale.isValid(anyInt())).thenAnswer(invocation -> { + Thread.sleep(1500); // a database that no longer answers: the validation waits out its bound + return false; + }); + final Connection good = mock(Connection.class); + when(good.isValid(anyInt())).thenReturn(true); + CachedConnection.cached.get(url).add(new CachedConnection(url, stale)); + CachedConnection.cached.get(url).add(new CachedConnection(url, good)); + final Connection fresh = mock(Connection.class); + stub.answerWith(fresh); + System.setProperty(CachedConnection.POOL_TIMEOUT_PROPERTY, "1"); + + final Connection borrowed = CachedConnection.getConnection(url); + + assertSame(((CachedConnection) borrowed).parent, fresh, "the drain must stop at the deadline"); + verify(stale).close(); + verify(good, never()).close(); + assertFalse(CachedConnection.cached.get(url).isEmpty(), "a connection the deadline was reached in front of was lost"); + } + + /** + * A connection the validation of which failed is on its way out, and its driver knows it: + * Connector/J answers a failed validation by aborting the connection and the SQL Server driver + * by terminating it. Putting the previous bound back on it fails, and warns about statements + * of a connection that is being closed - over an idle connection the server reaped, which is + * nobody's problem. + */ + @Test(timeOut = 120000) + public void testAConnectionOnItsWayOutIsNotGivenItsBoundBack() throws Exception { + final String url = StubDriver.PREFIX + "reaped-idle"; + final Connection reaped = mock(Connection.class); + when(reaped.getNetworkTimeout()).thenReturn(0); + when(reaped.isValid(anyInt())).thenReturn(false); + CachedConnection.cached.get(url).add(new CachedConnection(url, reaped)); + final Connection fresh = mock(Connection.class); + stub.answerWith(fresh); + + assertSame(((CachedConnection) CachedConnection.getConnection(url)).parent, fresh); + + verify(reaped).setNetworkTimeout(any(Executor.class), eq(CachedConnection.VALIDATION_TIMEOUT_SECONDS * 1000)); + verify(reaped, never()).setNetworkTimeout(any(Executor.class), eq(0)); + verify(reaped).close(); + } + + /** + * The read bound of the login is lifted once the login is through, because left in place it + * fails every statement slower than it. A driver that will not take it back leaves a + * connection that must not be pooled: it would carry that bound into every borrow the pool + * hands it to, an import batch among them. + */ + @Test(timeOut = 120000) + public void testAConnectionStillCarryingTheBoundOfItsLoginIsNotPooled() throws Exception { + final String url = StubDriver.PREFIX + "unliftable-bound"; + final Connection parent = mock(Connection.class); + doThrow(new SQLException("setNetworkTimeout is not supported")) + .when(parent).setNetworkTimeout(any(Executor.class), eq(0)); + stub.answerWith(parent); + + final CachedConnection borrowed = CachedConnection.connect(url, CachedConnection.ConnectDialect.MYSQL, 30); + borrowed.close(); + + verify(parent).close(); + assertTrue(CachedConnection.cached.get(url).isEmpty(), + "a connection still carrying the read bound of its login went back into the pool"); } private static SQLException tooManyConnections() { From 625e2f234397816ece240c09f9b8a2b7305bde64 Mon Sep 17 00:00:00 2001 From: Valera V Harseko Date: Thu, 20 Aug 2026 17:20:04 +0300 Subject: [PATCH 4/8] [#872] Keep the password out of the log, and the rest of what the review found open safeUrl() took the credentials off the first host of a url and assumed they end at the first "/", and the stall report of a database that takes no connection carried whatever was left into the server log. Both assumptions break on shapes Connector/J accepts: a failover or replication url gives every host credentials of its own ("//u:p@h1:3306,u2:p2@h2:3306"), and its key-value host syntax holds them inside the authority itself ("//address=(host=h)(user=u)(password=p)"), where neither a userinfo nor a parameter stands - so the password of the second host, or the whole one of a key-value url, reached logger.warn and the message of the SQLTimeoutException. Every userinfo of an authority is taken off now, a "password=" left standing anywhere is blanked out, and a url that none of this took apart is not logged past its subprotocol: the host of a stall report is worth less than a password in the server log. Both safeUrl() and the warning belong to this branch, so nothing of this reached a release. Also from the review, each one measured against the driver it is about: - Connector/J looks its properties up by their exact name, exactly as pgjdbc does - PropertyKey.fromValue("SocketTimeout") answers null, and the driver then reads no bound out of the url either. Taken for a bound of the administrator, a mis-cased parameter left a mysql backend with no read bound at all, which is the hang #872 is about; - a dotted property of the oracle driver is read out of the system properties as well, the way a whole jvm is bounded with -Doracle.jdbc.ReadTimeout: against a listener that completes the handshake and never speaks, -D alone gives up at 2.5 s and a Properties value of ours on top of it takes the timing over. That bound was then lifted after the login as if it were ours, leaving a connection with no read bound where the administrator had set one - so the system properties are looked up as well now; - RECV_TIMEOUT is a parameter of sqlnet.ora and of the listener that ojdbc8 never reads - the name appears in none of its classes - so a descriptor carrying one took our read bound off a connection that had none of its own, leaving an administrator who wrote a timeout with less than one who wrote nothing; - a property set to 0 is not a bound of the administrator either: every one of these drivers reads 0 as "wait as long as it takes". On postgresql a "?socketTimeout=0" was worse than no bound at all - loginTimeout alone hands the login to the daemon thread pgjdbc abandons at the timeout, and an unbounded read leaves it parked there with the socket it holds; - the bound handed to a driver stays inside the range an int of milliseconds takes: with ...jdbc.connect.timeout at 0 an attempt takes what is left of the deadline, ...jdbc.pool.timeout has no upper bound of its own, and mssql-jdbc rejects a socketTimeout past Integer.MAX_VALUE outright ("The socketTimeout 3000000000 is not valid"), failing every connect of that backend with the name of a property nobody typed; - the validation of a pooled connection catches an unchecked failure of a driver as well: it would unwind through poll(), which stands outside every try of the borrow, and leave the connection dequeued and closed by nobody. And three comments that described the right behaviour after the wrong code: the SO_TIMEOUT of a pgjdbc login is put on in tryConnect rather than in openConnectionImpl; the connect of a multi-host url is one budget for all of its hosts, taken from the single System.nanoTime() in front of the loop over them, rather than one per host; and ...jdbc.pool.timeout bounds a borrow, but not to the millisecond - the connection in hand is validated whatever the deadline says and an attempt is never given less than a second. CachedConnectionTestCase is at 32 tests, still without a database and ~20 s. Each of the fixes above was put back one at a time, and the assertion that covers it failed. --- .../backends/jdbc/CachedConnection.java | 244 ++++++++++++------ .../jdbc/CachedConnectionTestCase.java | 185 ++++++++++++- 2 files changed, 346 insertions(+), 83 deletions(-) diff --git a/opendj-server-legacy/src/main/java/org/opends/server/backends/jdbc/CachedConnection.java b/opendj-server-legacy/src/main/java/org/opends/server/backends/jdbc/CachedConnection.java index e312d5504b..693b66ff4a 100644 --- a/opendj-server-legacy/src/main/java/org/opends/server/backends/jdbc/CachedConnection.java +++ b/opendj-server-legacy/src/main/java/org/opends/server/backends/jdbc/CachedConnection.java @@ -30,6 +30,7 @@ import java.util.Properties; import java.util.concurrent.*; import java.util.concurrent.atomic.AtomicLong; +import java.util.regex.Pattern; public class CachedConnection implements Connection { private static final LocalizedLogger logger = LocalizedLogger.getLoggerForThisClass(); @@ -46,7 +47,12 @@ public class CachedConnection implements Connection { static final String CONNECT_TIMEOUT_PROPERTY = "org.openidentityplatform.opendj.jdbc.connect.timeout"; static final long DEFAULT_CONNECT_TIMEOUT_SECONDS = 30; - /** Bounds a whole borrow - every connect attempt and every wait for a pooled connection - in seconds; 0 for no bound. */ + /** + * Bounds a whole borrow - every connect attempt and every wait for a pooled connection - in + * seconds; 0 for no bound. Not to the millisecond: the connection in hand is validated + * whatever the deadline says, and an attempt is never given less than a second, so a borrow + * can return a validation and a last attempt past it. + */ static final String POOL_TIMEOUT_PROPERTY = "org.openidentityplatform.opendj.jdbc.pool.timeout"; static final long DEFAULT_POOL_TIMEOUT_SECONDS = 60; @@ -65,6 +71,11 @@ public class CachedConnection implements Connection { /** How many links of the cause and getNextException() chains of a failure are looked at. */ private static final int MAX_CHAIN_LENGTH = 32; + /** What a connection string is cut down to where this cannot tell its credentials from the rest of it. */ + static final String CREDENTIALS_HIDDEN = "