This is an automated email from the ASF dual-hosted git repository. rmaucher pushed a commit to branch 9.0.x in repository https://gitbox.apache.org/repos/asf/tomcat.git
commit f5deb20aa813ff61614536dde83433a52d3fe9fe Author: opencode <[email protected]> AuthorDate: Thu Nov 5 20:54:47 2026 +0100 Report duplicate live pool names as an error Pool names are the key under which the slow query report publishes its statistics and its JMX registration, so they have to be unique among live pools. Tomcat assigns a name of its own to every pool it manages; a programmatically built pool could still be given the name of a live pool, in which case the two pools displaced each other's statistics store with no diagnostic. Document that requirement on PoolConfiguration, SlowQueryReport and SlowQueryReportJmx, and report a pool that starts under a live pool's name at error level. Each statistics store now refers to its pool weakly, which distinguishes a live holder of the name from a store an abandoned, collected pool left behind; the latter is still taken over silently. Add a log-capture regression test and the corresponding LocalStrings message. --- .../apache/tomcat/jdbc/pool/PoolConfiguration.java | 11 +-- .../jdbc/pool/interceptor/SlowQueryReport.java | 73 +++++++++++++---- .../jdbc/pool/interceptor/SlowQueryReportJmx.java | 9 ++- .../tomcat/jdbc/pool/util/LocalStrings.properties | 1 + .../TestSlowQueryJmxSlowQueriesCDRace.java | 2 +- .../interceptor/TestSlowQueryReportPoolNames.java | 92 +++++++++++++++++++++- webapps/docs/changelog.xml | 9 +++ 7 files changed, 170 insertions(+), 27 deletions(-) diff --git a/modules/jdbc-pool/src/main/java/org/apache/tomcat/jdbc/pool/PoolConfiguration.java b/modules/jdbc-pool/src/main/java/org/apache/tomcat/jdbc/pool/PoolConfiguration.java index d2dfab988a..ea68022bfc 100644 --- a/modules/jdbc-pool/src/main/java/org/apache/tomcat/jdbc/pool/PoolConfiguration.java +++ b/modules/jdbc-pool/src/main/java/org/apache/tomcat/jdbc/pool/PoolConfiguration.java @@ -404,10 +404,11 @@ public interface PoolConfiguration { void setMinIdle(int minIdle); /** - * Returns the name of the connection pool. By default a name unique within this class loader is assigned; it is a - * counter, so it is unique but predictable, not random. Two class loaders that each load this module can therefore - * produce the same default name, which the pool's statistics and JMX registration treat as the same name: give - * pools that must coexist a name of their own. + * Returns the name of the connection pool. Tomcat gives every pool it manages a name of its own. By default a + * name unique within this class loader is assigned; it is a counter, so it is unique but predictable, not random. + * Two class loaders that each load this module can therefore produce the same default name, which the pool's + * statistics and JMX registration treat as the same name: give pools that must coexist a name of their own. A + * duplicate name among live pools is reported as an error by the query reporting interceptors. * * @return the name of the pool, unique within this class loader by default */ @@ -416,7 +417,7 @@ public interface PoolConfiguration { /** * Sets the name of the connection pool * - * @param name the name of the pool, should be unique among the pools that share its statistics and JMX space + * @param name the name of the pool, unique among the live pools that share its statistics and JMX space */ void setName(String name); diff --git a/modules/jdbc-pool/src/main/java/org/apache/tomcat/jdbc/pool/interceptor/SlowQueryReport.java b/modules/jdbc-pool/src/main/java/org/apache/tomcat/jdbc/pool/interceptor/SlowQueryReport.java index dfee7eb379..2d45744490 100644 --- a/modules/jdbc-pool/src/main/java/org/apache/tomcat/jdbc/pool/interceptor/SlowQueryReport.java +++ b/modules/jdbc-pool/src/main/java/org/apache/tomcat/jdbc/pool/interceptor/SlowQueryReport.java @@ -16,6 +16,7 @@ */ package org.apache.tomcat.jdbc.pool.interceptor; +import java.lang.ref.WeakReference; import java.text.SimpleDateFormat; import java.util.ArrayList; import java.util.Collections; @@ -46,9 +47,12 @@ import org.apache.tomcat.jdbc.pool.util.MessageFactory; * The statistics belong to the pool the interceptor serves: a pool registers its store when it starts and releases it * when it closes, and every connection of that pool books its executions into that one store. The store is read by the * name the pool started with - see {@link ConnectionPool#getRegistrationName()} and {@link #getPoolStats(String)}. - * The name identifies the pool: a container names every pool it manages uniquely, and the default name of a - * programmatically built pool is unique as well. Renaming a running pool, which the pool's own JMX allows, neither - * detaches the pool from its statistics nor strands what its start published. + * The name identifies the pool, so it must be unique among the live pools of this class loader: Tomcat gives every + * pool it manages a name of its own, and a programmatically built pool has a unique default name. A pool that starts + * under a name a live pool already holds is a configuration error, reported as such, and its statistics displace the + * other pool's store under the shared name. + * Renaming a running pool, which the pool's own JMX allows, neither detaches the pool from its statistics nor strands + * what its start published. * </p> * <p> * A reporting definition the interceptor list gains after the start is not stranded either: the list is mutable at @@ -56,8 +60,8 @@ import org.apache.tomcat.jdbc.pool.util.MessageFactory; * the close that releases the store is told about that definition as well. * </p> * <p> - * The registrations hold no reference to the pool, so a pool abandoned without closing is never pinned by them and can - * be collected with its open sessions, leaving only the bounded statistics store published under its name until a pool + * The registrations hold the pool only weakly, so a pool abandoned without closing is never pinned by them and can be + * collected with its open sessions, leaving only the bounded statistics store published under its name until a pool * starting under that name takes the name over. * </p> * <p> @@ -370,12 +374,36 @@ public class SlowQueryReport extends AbstractQueryReport { // ConcurrentHashMap would refuse the key before anything else could throw new IllegalStateException(MessageFactory.get("slowQueryReport.poolNameRequired")); } - PoolStatistics own = new PoolStatistics(name); - perPoolStats.put(name, own); + PoolStatistics own = new PoolStatistics(pool, name); + synchronized (perPoolStats) { + reportDuplicateName(perPoolStats.put(name, own), pool, name); + } this.poolStatistics = own; this.queries = own.getQueryStats(); } + /** + * Reports a pool that takes a name a live pool already holds. The name is the key both the statistics and the JMX + * registration are published under, so two live pools sharing it cannot be told apart: the registry, like the + * MBeanServer, keeps one of them. That is a configuration error rather than a supported way to share reporting - + * Tomcat gives every pool it manages a name of its own - so it is reported at error level. A store whose pool has + * been collected is not a live duplicate: a pool that starts under the name an abandoned pool left behind takes + * the name over without a report. + * + * @param previous the store the name held before, or {@code null} when it held none + * @param pool the pool that registered the store now + * @param name the name both pools carry + */ + private static void reportDuplicateName(PoolStatistics previous, ConnectionPool pool, String name) { + if (previous == null) { + return; + } + ConnectionPool owner = previous.getPool(); + if (owner != null && owner != pool) { + log.error(MessageFactory.get("slowQueryReport.duplicatePoolName", name)); + } + } + /** * Resolves the store the borrow this instance serves is to book into, registering the pool's store when this * instance is the first component of that pool to need one. @@ -415,8 +443,8 @@ public class SlowQueryReport extends AbstractQueryReport { } own = perPoolStats.get(name); if (own == null) { - own = new PoolStatistics(name); - perPoolStats.put(name, own); + own = new PoolStatistics(parent, name); + reportDuplicateName(perPoolStats.put(name, own), parent, name); } return own; } @@ -770,13 +798,19 @@ public class SlowQueryReport extends AbstractQueryReport { /** * The query statistics of one pool: the map its connections book into and the name the map is published under. * <p> - * The store holds no reference to the pool. The name identifies the pool - a container names its pools uniquely, - * and the default name of a programmatic pool is unique as well - so the store can outlive a pool abandoned without - * closing without pinning that pool, together with everything it reaches: its queues, its pooled connections and - * their open physical sessions. + * The store refers to the pool only weakly. The name identifies the pool and must be unique among live pools - + * Tomcat names every pool it manages, and the default name of a programmatic pool is unique as well - so the store + * can outlive a pool abandoned without closing without pinning that pool, together with everything it reaches: its + * queues, its pooled connections and their open physical sessions. The weak reference is what tells a live holder + * of the name from an abandoned pool's leftover store. * </p> */ protected static class PoolStatistics { + /** + * the pool this store belongs to, held weakly so that the store never pins a pool abandoned without closing; + * used to tell a live pool holding the name from one whose store is all that is left of it + */ + private final WeakReference<ConnectionPool> pool; /** * the name this store is published under - the registration name of the pool at its start */ @@ -800,12 +834,23 @@ public class SlowQueryReport extends AbstractQueryReport { /** * Creates the statistics store of one pool. * + * @param pool the pool the store belongs to * @param name the name the store is published under */ - protected PoolStatistics(String name) { + protected PoolStatistics(ConnectionPool pool, String name) { + this.pool = new WeakReference<>(pool); this.name = name; } + /** + * Returns the pool this store belongs to while it is still reachable. + * + * @return the owning pool, or {@code null} once it has been collected + */ + protected ConnectionPool getPool() { + return pool.get(); + } + /** * Returns the name this store is published under. * diff --git a/modules/jdbc-pool/src/main/java/org/apache/tomcat/jdbc/pool/interceptor/SlowQueryReportJmx.java b/modules/jdbc-pool/src/main/java/org/apache/tomcat/jdbc/pool/interceptor/SlowQueryReportJmx.java index eed1bfd505..05f2994574 100644 --- a/modules/jdbc-pool/src/main/java/org/apache/tomcat/jdbc/pool/interceptor/SlowQueryReportJmx.java +++ b/modules/jdbc-pool/src/main/java/org/apache/tomcat/jdbc/pool/interceptor/SlowQueryReportJmx.java @@ -65,10 +65,11 @@ import org.apache.tomcat.jdbc.pool.util.MessageFactory; * The pool start callback only records the pool and its registration name; an idle pool is not published, so * monitoring begins with the first borrow. * They are published under the name the pool started with - see {@link ConnectionPool#getRegistrationName()} - which - * identifies the pool, because a container names every pool it manages uniquely and the default name of a - * programmatically built pool is unique as well. Renaming a running pool, which the pool's own JMX allows, moves - * nothing: the MBean stays published under the name it was registered under and the pool keeps reporting through it. - * The close of that pool gives both up. + * identifies the pool and must be unique among the live pools of a class loader: Tomcat gives every pool it manages a + * name of its own, and a programmatically built pool has a unique default name. A duplicate live name is reported as + * an error by the pool start, and only one of the pools can hold the ObjectName. Renaming a running pool, which the + * pool's own JMX allows, moves nothing: the MBean stays published under the name it was registered under and the pool + * keeps reporting through it. The close of that pool gives both up. * </p> * <p> * The published resource is a {@link Registration}, not an interceptor instance: it holds the name, the statistics diff --git a/modules/jdbc-pool/src/main/java/org/apache/tomcat/jdbc/pool/util/LocalStrings.properties b/modules/jdbc-pool/src/main/java/org/apache/tomcat/jdbc/pool/util/LocalStrings.properties index 08030473e9..76bb710add 100644 --- a/modules/jdbc-pool/src/main/java/org/apache/tomcat/jdbc/pool/util/LocalStrings.properties +++ b/modules/jdbc-pool/src/main/java/org/apache/tomcat/jdbc/pool/util/LocalStrings.properties @@ -206,6 +206,7 @@ resetAbandonedTimer.unableToCreateTimerResultSetProxy=Unable to create timer res resetAbandonedTimer.unableToCreateTimerStatementProxy=Unable to create timer statement proxy for {0}. slowQueryReport.connectionClosedOrAbandoned=A slow query report interceptor has no statistics store to book to, so the queries it reports are recorded nowhere: the connection it serves has already been closed or abandoned, or its pool carries no name to publish statistics under - statistics belong to a pool and are published under the name that pool starts with. This is reported once per interceptor instance, because the condition outlives every execution that follows it. +slowQueryReport.duplicatePoolName=Duplicate pool name [{0}]: a pool name must be unique among the live pools of a class loader, because it is the key the slow query statistics and the JMX registration are published under. Tomcat gives every pool it manages a name of its own; give a pool built programmatically a unique name as well. The statistics and the JMX registration of the pool that started under the name first are displaced by the pool that started last. slowQueryReport.failedQueryReport=Failed Query Report SQL={0}; time={1} ms; slowQueryReport.invalidLogFailed=The configured logFailed [{0}] is neither true nor false and is not applied: failed query logging keeps the setting it carries, [{1}]. Correct the value in the jdbcInterceptors configuration to change what is logged there. slowQueryReport.invalidLogSlow=The configured logSlow [{0}] is neither true nor false and is not applied: slow query logging keeps the setting it carries, [{1}]. Correct the value in the jdbcInterceptors configuration to change what is logged there. diff --git a/modules/jdbc-pool/src/test/java/org/apache/tomcat/jdbc/pool/interceptor/TestSlowQueryJmxSlowQueriesCDRace.java b/modules/jdbc-pool/src/test/java/org/apache/tomcat/jdbc/pool/interceptor/TestSlowQueryJmxSlowQueriesCDRace.java index db7efae609..983cc4f3b8 100644 --- a/modules/jdbc-pool/src/test/java/org/apache/tomcat/jdbc/pool/interceptor/TestSlowQueryJmxSlowQueriesCDRace.java +++ b/modules/jdbc-pool/src/test/java/org/apache/tomcat/jdbc/pool/interceptor/TestSlowQueryJmxSlowQueriesCDRace.java @@ -118,7 +118,7 @@ class TestSlowQueryJmxSlowQueriesCDRace { */ private static ConcurrentHashMap<String, QueryStats> seedStats(String poolName) { assertBinsInvisitOrder(); - SlowQueryReport.PoolStatistics statistics = new SlowQueryReport.PoolStatistics(poolName); + SlowQueryReport.PoolStatistics statistics = new SlowQueryReport.PoolStatistics(null, poolName); SlowQueryReport.perPoolStats.put(poolName, statistics); ConcurrentHashMap<String, QueryStats> live = statistics.getQueryStats(); live.put(MIDDLE, new QueryStats(MIDDLE)); diff --git a/modules/jdbc-pool/src/test/java/org/apache/tomcat/jdbc/pool/interceptor/TestSlowQueryReportPoolNames.java b/modules/jdbc-pool/src/test/java/org/apache/tomcat/jdbc/pool/interceptor/TestSlowQueryReportPoolNames.java index 35a8e88608..7ed376477b 100644 --- a/modules/jdbc-pool/src/test/java/org/apache/tomcat/jdbc/pool/interceptor/TestSlowQueryReportPoolNames.java +++ b/modules/jdbc-pool/src/test/java/org/apache/tomcat/jdbc/pool/interceptor/TestSlowQueryReportPoolNames.java @@ -19,21 +19,28 @@ package org.apache.tomcat.jdbc.pool.interceptor; import java.sql.Connection; import java.sql.SQLException; import java.sql.Statement; +import java.util.ArrayList; import java.util.Collections; +import java.util.List; import java.util.concurrent.ConcurrentHashMap; +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.DataSource; /** * The {@code SlowQueryReport} publishes a pool's statistics under the name the * pool started with, and reads them back by that name. The name identifies the - * pool - a container names every pool it manages uniquely, and the default name - * of a programmatically built pool is unique as well - so each pool has one - * store and one close releases only that store. + * pool and must be unique among the live pools of a class loader: Tomcat gives + * every pool it manages a name of its own, and a programmatically built pool + * has a unique default name. A duplicate live name is reported as an error. */ class TestSlowQueryReportPoolNames extends JdbcPoolBaseTest { @@ -106,6 +113,25 @@ class TestSlowQueryReportPoolNames extends JdbcPoolBaseTest { "closing the pool that holds the name must release its statistics"); } + @Test + void aDuplicateLivePoolNameIsReportedAsAnError() throws Exception { + String poolName = "duplicate-" + System.nanoTime(); + try (ReportLogCapture logs = new ReportLogCapture()) { + DataSource first = reportedPoolNamed(poolName); + first.createPool(); + run(first, QUERY_FIRST); + + DataSource second = reportedPoolNamed(poolName); + second.createPool(); + run(second, QUERY_SECOND); + + logs.assertDuplicateReported(poolName); + + second.close(); + first.close(); + } + } + @Test void aPoolStartedUnderAFreedNameCollectsIntoAFreshStore() throws Exception { String poolName = "reuse-" + System.nanoTime(); @@ -129,4 +155,64 @@ class TestSlowQueryReportPoolNames extends JdbcPoolBaseTest { second.close(); } + + /** + * Captures what {@link SlowQueryReport} logs through the JULI logger the + * interceptor uses. + */ + private static final class ReportLogCapture implements AutoCloseable { + private static final String CANARY = "slow-query-report-handler-wiring-canary"; + + private final Logger logger = Logger.getLogger(SlowQueryReport.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 + } + }; + + ReportLogCapture() { + logger.addHandler(handler); + logger.setLevel(Level.ALL); + LogFactory.getLog(SlowQueryReport.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"); + } + } + + void assertDuplicateReported(String poolName) { + LogRecord[] snapshot; + synchronized (records) { + snapshot = records.toArray(new LogRecord[0]); + } + for (LogRecord record : snapshot) { + if (record.getLevel().intValue() >= Level.SEVERE.intValue() && record.getMessage() != null + && record.getMessage().contains("Duplicate pool name") + && record.getMessage().contains(poolName)) { + return; + } + } + Assertions.fail("a pool that starts under the name of a live pool must report the" + + " duplicate name as an error, saw no such record for " + poolName); + } + + @Override + public void close() { + logger.removeHandler(handler); + logger.setLevel(originalLevel); + } + } } diff --git a/webapps/docs/changelog.xml b/webapps/docs/changelog.xml index c475674952..e80e0ea4c8 100644 --- a/webapps/docs/changelog.xml +++ b/webapps/docs/changelog.xml @@ -1360,6 +1360,15 @@ the connection and reports the failure as an <code>SQLException</code>. (remm) </fix> + <fix> + Report a duplicate live pool name as an error from the JDBC pool's slow + query reporting interceptors. Tomcat gives every pool it manages a name + of its own, but a pool built programmatically can be given the name of a + live pool, and the statistics and the JMX registration are keyed by that + name: the two pools then displaced each other's statistics store. The + name is documented as having to be unique among live pools, and a + duplicate is reported at error level. (remm) + </fix> </changelog> </subsection> <subsection name="Other"> --------------------------------------------------------------------- To unsubscribe, e-mail: [email protected] For additional commands, e-mail: [email protected]
