This is an automated email from the ASF dual-hosted git repository. rmaucher pushed a commit to branch 11.0.x in repository https://gitbox.apache.org/repos/asf/tomcat.git
commit 0cbb0ead3292dd5c7064ffb51c33e99dad955dea Author: opencode <[email protected]> AuthorDate: Fri Oct 30 13:01:49 2026 +0100 Warn at pool start when StatementCache is configured before QueryTimeoutInterceptor The pool answers a statement cache hit without invoking interceptors listed after the cache, and recycling zeroes the cached statement's timeout, so a pool that lists StatementCache before QueryTimeoutInterceptor runs every cached statement with no timeout at all - silently, as the requirement was documentation-only. Scan the parsed interceptor definitions once at pool start and log a warning when a cache occurrence is listed before a timeout occurrence, naming both interceptors and the required order. Class resolution is the pool's own, so short, fully-qualified and parameterized entries are detected alike; the check cannot fail pool startup. --- .../apache/tomcat/jdbc/pool/ConnectionPool.java | 49 ++++++++ .../TestQueryTimeoutWithStatementCache.java | 136 ++++++++++++++++++++- 2 files changed, 184 insertions(+), 1 deletion(-) diff --git a/modules/jdbc-pool/src/main/java/org/apache/tomcat/jdbc/pool/ConnectionPool.java b/modules/jdbc-pool/src/main/java/org/apache/tomcat/jdbc/pool/ConnectionPool.java index e41018bf53..6d0ea2b268 100644 --- a/modules/jdbc-pool/src/main/java/org/apache/tomcat/jdbc/pool/ConnectionPool.java +++ b/modules/jdbc-pool/src/main/java/org/apache/tomcat/jdbc/pool/ConnectionPool.java @@ -48,6 +48,8 @@ import javax.sql.XAConnection; import org.apache.juli.logging.Log; import org.apache.juli.logging.LogFactory; +import org.apache.tomcat.jdbc.pool.interceptor.QueryTimeoutInterceptor; +import org.apache.tomcat.jdbc.pool.interceptor.StatementCache; /** * Implementation of simple connection pool. The ConnectionPool uses a {@link PoolProperties} object for storing all the @@ -694,6 +696,11 @@ public class ConnectionPool { throw ex; } } + // Every interceptor class has now been loaded and instantiated above, + // so the parsed definitions can be compared against each other. The + // relative order of two interceptors in the chain is not something a + // single interceptor can see; only the pool holds the ordered list. + checkInterceptorOrder(proxies); // Initialize the pool with its initial set of members PooledConnection[] initialPool = new PooledConnection[poolProperties.getInitialSize()]; @@ -727,6 +734,48 @@ public class ConnectionPool { closed = false; } + /** + * Warns once at pool start when the configured interceptor chain lets the statement cache answer a cache hit + * before the query timeout interceptor can re-apply its timeout. A + * {@link org.apache.tomcat.jdbc.pool.interceptor.StatementCache} hit is served without invoking the rest of the + * chain, and a statement recycled into the cache carries query timeout zero, so a + * {@link org.apache.tomcat.jdbc.pool.interceptor.QueryTimeoutInterceptor} listed after the cache never sees the + * reuse and every cached statement executes with no timeout. The chain is built back-to-front in + * {@link #setupConnection(PooledConnection)}, making the first-listed interceptor the outermost one, so the + * timeout interceptor must be listed before the cache. This detection only reports the misconfiguration; no + * behaviour is changed. + * + * @param proxies the parsed interceptor definitions, in configuration order + */ + private void checkInterceptorOrder(PoolProperties.InterceptorDefinition[] proxies) { + int firstCache = -1; + int lastTimeout = -1; + for (int i = 0; i < proxies.length; i++) { + try { + Class<? extends JdbcInterceptor> interceptorClass = proxies[i].getInterceptorClass(); + if (StatementCache.class == interceptorClass) { + if (firstCache < 0) { + firstCache = i; + } + } else if (QueryTimeoutInterceptor.class == interceptorClass) { + lastTimeout = i; + } + } catch (ReflectiveOperationException | LinkageError x) { + // The pool-start loop above has already loaded and instantiated every one of these classes, so + // resolution cannot fail here. This check is diagnostic only; if it ever does fail, say nothing + // rather than disturbing a pool that started successfully. + return; + } + } + if (firstCache >= 0 && lastTimeout > firstCache) { + log.warn("The [StatementCache] interceptor is configured before [QueryTimeoutInterceptor]. " + + "A statement cache hit is answered by the cache without invoking the timeout interceptor, " + + "and a statement recycled into the cache carries no timeout, so cached statements run " + + "without a query timeout. List QueryTimeoutInterceptor before StatementCache in the " + + "jdbcInterceptors configuration."); + } + } + /** * Validates and corrects pool configuration values. Ensures that maxActive, initialSize, minIdle, maxIdle, and * related values are consistent. diff --git a/modules/jdbc-pool/src/test/java/org/apache/tomcat/jdbc/pool/interceptor/TestQueryTimeoutWithStatementCache.java b/modules/jdbc-pool/src/test/java/org/apache/tomcat/jdbc/pool/interceptor/TestQueryTimeoutWithStatementCache.java index 4c357fcc5f..fab5f7eac5 100644 --- a/modules/jdbc-pool/src/test/java/org/apache/tomcat/jdbc/pool/interceptor/TestQueryTimeoutWithStatementCache.java +++ b/modules/jdbc-pool/src/test/java/org/apache/tomcat/jdbc/pool/interceptor/TestQueryTimeoutWithStatementCache.java @@ -20,11 +20,21 @@ import java.sql.Connection; import java.sql.PreparedStatement; import java.sql.SQLException; import java.sql.Statement; +import java.util.ArrayList; +import java.util.Arrays; +import java.util.Collections; +import java.util.List; +import java.util.logging.Handler; +import java.util.logging.Level; +import java.util.logging.LogRecord; +import java.util.logging.Logger; import org.junit.jupiter.api.Assertions; import org.junit.jupiter.api.Test; +import org.apache.juli.logging.LogFactory; import org.apache.tomcat.jdbc.JdbcPoolBaseTest; +import org.apache.tomcat.jdbc.pool.ConnectionPool; import org.apache.tomcat.jdbc.pool.DataSource; /** @@ -35,7 +45,8 @@ import org.apache.tomcat.jdbc.pool.DataSource; * the cache carries query timeout 0. The ordering in * {@code jdbcInterceptors} therefore decides whether reused statements * keep the configured timeout - a requirement now documented on the - * interceptor and in the jdbc-pool docs, and pinned here in both orders. + * interceptor and in the jdbc-pool docs, warned about by the pool at + * start when the cache is listed first, and pinned here in both orders. */ class TestQueryTimeoutWithStatementCache extends JdbcPoolBaseTest { @@ -115,4 +126,127 @@ class TestQueryTimeoutWithStatementCache extends JdbcPoolBaseTest { reused.close(); } } + + /** + * A pool whose chain lists the cache before the timeout interceptor + * answers every repeated prepare of the same SQL from the cache, around + * the deeper interceptor, with the timeout the cache reset to 0 - so + * ConnectionPool warns about the ordering once when the pool starts. + */ + @Test + void cacheListedFirstIsWarnedAboutAtPoolStart() throws Exception { + try (PoolLogCapture logs = new PoolLogCapture()) { + poolWith( + StatementCache.class.getName() + "(prepared=true,max=5)", + QueryTimeoutInterceptor.class.getName() + "(queryTimeout=5)"); + logs.assertOrderWarningLogged(); + } + } + + /** + * The reverse order is the documented configuration: the timeout + * interceptor sits outside the cache and re-applies the timeout on every + * hit, so there must be no warning. + */ + @Test + void timeoutListedFirstIsNotWarnedAbout() throws Exception { + try (PoolLogCapture logs = new PoolLogCapture()) { + poolWith( + QueryTimeoutInterceptor.class.getName() + "(queryTimeout=5)", + StatementCache.class.getName() + "(prepared=true,max=5)"); + logs.assertNoOrderWarningLogged(); + } + } + + /** + * The check runs against the parsed, resolved interceptor definitions, so + * a short name that only resolves against the interceptor package, and a + * parameterized entry whose parenthesized properties the parser strips, + * must normalize to the same comparison as the fully qualified spellings. + */ + @Test + void shortNamesNormalizeToTheSameOrderCheck() throws Exception { + try (PoolLogCapture logs = new PoolLogCapture()) { + poolWith("StatementCache", "QueryTimeoutInterceptor"); + logs.assertOrderWarningLogged(); + } + try (PoolLogCapture logs = new PoolLogCapture()) { + poolWith("QueryTimeoutInterceptor(queryTimeout=5)", "StatementCache(prepared=true)"); + logs.assertNoOrderWarningLogged(); + } + } + + /** + * Captures what {@link ConnectionPool} logs, following the handler idiom + * of the pool's other diagnostic tests. The canary record - written + * through the very JULI logger the pool logs through, not through JUL + * directly - proves the wiring observes those records before the pool + * under test gets its chance to log. + */ + private static final class PoolLogCapture implements AutoCloseable { + private static final String CANARY = "interceptor-order-handler-wiring-canary"; + + private final Logger logger = Logger.getLogger(ConnectionPool.class.getName()); + private final Level originalLevel = logger.getLevel(); + private final List<LogRecord> records = Collections.synchronizedList(new ArrayList<>()); + private final Handler handler = new Handler() { + @Override + public void publish(LogRecord record) { + records.add(record); + } + + @Override + public void flush() { + // no buffering + } + + @Override + public void close() { + // nothing to release + } + }; + + PoolLogCapture() { + logger.addHandler(handler); + logger.setLevel(Level.ALL); + LogFactory.getLog(ConnectionPool.class).error(CANARY); + if (records.stream().noneMatch(r -> CANARY.equals(r.getMessage()))) { + close(); + throw new AssertionError("the test handler must observe what this class logs"); + } + } + + private static boolean isOrderWarning(LogRecord record) { + return record.getLevel().intValue() == Level.WARNING.intValue() + && record.getMessage() != null + && record.getMessage().contains( + "[StatementCache] interceptor is configured before"); + } + + void assertOrderWarningLogged() { + Assertions.assertTrue(Arrays.stream(snapshot()).anyMatch(PoolLogCapture::isOrderWarning), + "a chain that lists the statement cache before the timeout interceptor" + + " must be warned about at pool start, records: " + + Arrays.toString(snapshot())); + } + + void assertNoOrderWarningLogged() { + for (LogRecord record : snapshot()) { + Assertions.assertFalse(isOrderWarning(record), + "a correctly ordered chain must not be warned about: " + record.getMessage()); + } + } + + private LogRecord[] snapshot() { + synchronized (records) { + return records.toArray(new LogRecord[0]); + } + } + + @Override + public void close() { + logger.removeHandler(handler); + logger.setLevel(originalLevel); + } + } } --------------------------------------------------------------------- To unsubscribe, e-mail: [email protected] For additional commands, e-mail: [email protected]
