This is an automated email from the ASF dual-hosted git repository. rmaucher pushed a commit to branch main in repository https://gitbox.apache.org/repos/asf/tomcat.git
commit dbeedffbad3baf44575452e329305f366ea72b7e Author: opencode <[email protected]> AuthorDate: Thu Oct 29 10:03:52 2026 +0100 Format the abandoned connection trace only when a report reads it With logAbandoned enabled, every borrow captured a thread dump and formatted it into a string straight away, although only the rare reported abandonment ever reads the trace back; the dumps of all the other borrows were paid for and thrown away. The borrow now stores just the stack trace elements of the borrow site, and the first read of the trace formats them and caches the text, so a reported abandonment - which logs the trace and notifies of it - pays for a single formatting and an unreported borrow pays for none. The text a report produces is what the eager formatting always produced. The trace is written and read under the lock of the pooled connection; the formatting works from a local snapshot of the elements, as the return of the connection clears the trace without waiting for a reader that has already looked. Patch by: sainadh777 Pull request: https://github.com/apache/tomcat/pull/1048 --- TODO.md | 10 -- .../apache/tomcat/jdbc/pool/ConnectionPool.java | 18 ++- .../apache/tomcat/jdbc/pool/PooledConnection.java | 39 +++++- .../tomcat/jdbc/pool/TestAbandonedTrace.java | 141 +++++++++++++++++++++ webapps/docs/changelog.xml | 9 ++ 5 files changed, 201 insertions(+), 16 deletions(-) diff --git a/TODO.md b/TODO.md index 6551487678..2c59b2afb3 100644 --- a/TODO.md +++ b/TODO.md @@ -432,16 +432,6 @@ These are bugs, correctness issues, or missing functionality that may affect pro --- -### 39. Connection Pool Thread Dump Optimization (1 item) - -| # | File:Line | Description | Fix Idea | Effort | Difficulty | -|---|-----------|-------------|----------|--------|------------| -| 39.1 | `ConnectionPool.java:1273` | Stores full stack trace string; could store `StackTraceElement[]` directly | Change `getThreadDump()` to return `StackTraceElement[]`. Store array and format on-demand for display. Saves memory. | 0.5-1 day | Low | - -**Total estimated effort: 0.5-1 day, Low difficulty** - ---- - ### 40. JDBC Pool JNDI Lookup (1 item) | # | File:Line | Description | Fix Idea | Effort | Difficulty | 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 0705f1e35f..7cdf8016c9 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 @@ -989,7 +989,7 @@ public class ConnectionPool { //no need to lock a new one, its not contented con.setTimestamp(now); if (getPoolProperties().isLogAbandoned()) { - con.setStackTrace(getThreadDump()); + con.setStackTraceElements(getThreadDumpElements()); } if (!busy.offer(con)) { log.debug("Connection doesn't fit into busy array, connection will not be traceable."); @@ -1057,7 +1057,7 @@ public class ConnectionPool { con.setTimestamp(now); if (getPoolProperties().isLogAbandoned()) { //set the stack trace for this pool - con.setStackTrace(getThreadDump()); + con.setStackTraceElements(getThreadDumpElements()); } if (!busy.offer(con)) { log.debug("Connection doesn't fit into busy array, connection will not be traceable."); @@ -1081,7 +1081,7 @@ public class ConnectionPool { con.setTimestamp(now); if (getPoolProperties().isLogAbandoned()) { //set the stack trace for this pool - con.setStackTrace(getThreadDump()); + con.setStackTraceElements(getThreadDumpElements()); } if (!busy.offer(con)) { log.debug("Connection doesn't fit into busy array, connection will not be traceable."); @@ -1512,7 +1512,6 @@ public class ConnectionPool { /** * Creates a stack trace representing the existing thread's current state. * @return a string object representing the current state. - * TODO investigate if we simply should store {@link java.lang.Thread#getStackTrace()} elements */ protected static String getThreadDump() { Exception x = new Exception(); @@ -1520,6 +1519,17 @@ public class ConnectionPool { return getStackTrace(x); } + /** + * Captures the existing thread's current state without formatting it. + * An abandoned connection reports the borrow site only rarely, so the + * formatting is left to {@link PooledConnection#getStackTrace()} and a + * borrow that is never reported never pays for a thread dump. + * @return the stack trace elements representing the current state + */ + protected static StackTraceElement[] getThreadDumpElements() { + return new Exception().getStackTrace(); + } + /** * Convert an exception into a String * @param x - the throwable diff --git a/modules/jdbc-pool/src/main/java/org/apache/tomcat/jdbc/pool/PooledConnection.java b/modules/jdbc-pool/src/main/java/org/apache/tomcat/jdbc/pool/PooledConnection.java index 8dda632fdc..52b85b166d 100644 --- a/modules/jdbc-pool/src/main/java/org/apache/tomcat/jdbc/pool/PooledConnection.java +++ b/modules/jdbc-pool/src/main/java/org/apache/tomcat/jdbc/pool/PooledConnection.java @@ -91,9 +91,17 @@ public class PooledConnection implements PooledConnectionMBean { */ private volatile javax.sql.PooledConnection cpdsConnection; /** - * When we track abandon traces, this string holds the thread dump + * When we track abandon traces, this string holds the formatted thread dump */ private String abandonTrace = null; + /** + * When we track abandon traces, the frames of the borrow site as they + * were captured, until an abandoned-connection report reads the trace + * and they are formatted into {@link #abandonTrace}. A pool with + * logAbandoned borrows constantly and reports rarely, so the + * formatting cost is only paid when the trace is actually read. + */ + private StackTraceElement[] abandonTraceElements = null; /** * Timestamp the connection was last 'touched' by the pool */ @@ -809,6 +817,19 @@ public class PooledConnection implements PooledConnectionMBean { public void setStackTrace(String trace) { abandonTrace = trace; + abandonTraceElements = null; + } + + /** + * The pool will set the borrow-site frames when it hands the + * connection out; they are formatted into a trace only if an + * abandoned-connection report reads it back. The pool writes and + * reads the trace under the lock of this connection. + * @param trace the borrow-site frames for this connection + */ + void setStackTraceElements(StackTraceElement[] trace) { + abandonTraceElements = trace; + abandonTrace = null; } /** @@ -816,7 +837,21 @@ public class PooledConnection implements PooledConnectionMBean { * @return the stack trace or null of no trace was set */ public String getStackTrace() { - return abandonTrace; + String trace = abandonTrace; + if (trace == null) { + //format the deferred borrow site, if one is pending, and cache + //the result: the abandon path logs the trace and notifies of it, + //and both readings should pay for a single formatting + StackTraceElement[] elements = abandonTraceElements; + if (elements != null) { + Exception x = new Exception(); + x.setStackTrace(elements); + trace = ConnectionPool.getStackTrace(x); + abandonTrace = trace; + abandonTraceElements = null; + } + } + return trace; } /** diff --git a/modules/jdbc-pool/src/test/java/org/apache/tomcat/jdbc/pool/TestAbandonedTrace.java b/modules/jdbc-pool/src/test/java/org/apache/tomcat/jdbc/pool/TestAbandonedTrace.java new file mode 100644 index 0000000000..3cbdf21eac --- /dev/null +++ b/modules/jdbc-pool/src/test/java/org/apache/tomcat/jdbc/pool/TestAbandonedTrace.java @@ -0,0 +1,141 @@ +/* + * Licensed to the Apache Software Foundation (ASF) under one or more + * contributor license agreements. See the NOTICE file distributed with + * this work for additional information regarding copyright ownership. + * The ASF licenses this file to You under the Apache License, Version 2.0 + * (the "License"); you may not use this file except in compliance with + * the License. You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ +package org.apache.tomcat.jdbc.pool; + +import java.lang.reflect.Field; +import java.sql.Connection; +import java.util.List; +import java.util.concurrent.CopyOnWriteArrayList; + +import javax.management.Notification; +import javax.management.NotificationListener; + +import org.junit.jupiter.api.Assertions; +import org.junit.jupiter.api.Test; + +import org.apache.tomcat.jdbc.JdbcPoolBaseTest; + +/** + * The abandoned-connection trace is recorded as the borrow-site stack + * trace elements and is formatted into the reported thread-dump string + * only when a report reads it. A pool with {@code logAbandoned} borrows + * constantly and reports rarely, so a borrow that is never reported must + * not have paid for - or produced - a formatted dump, while the text an + * abandoned connection does report must be exactly what the eager + * formatting always produced: a {@code java.lang.Exception} header and + * the frames of the borrowing thread, delivered to the log and to the + * pool's JMX listeners. + * + * <p>Scenario harvested from pull request 1048, whose test drove the + * pool's internals with hand-built subclasses; here the deferral is read + * off a real borrow and the reported text is captured from the JMX + * notification an actual abandonment sends.</p> + */ +class TestAbandonedTrace extends JdbcPoolBaseTest { + + /* + * The trace fields are private and the point of the change is what + * they hold between the borrow and the first read, so they are read + * directly - the way the suite's other fixture reaches behind the + * pool's own accessors. + */ + private static Object traceField(PooledConnection pooled, String name) + throws ReflectiveOperationException { + Field field = PooledConnection.class.getDeclaredField(name); + field.setAccessible(true); + return field.get(pooled); + } + + /* The pooled connection behind a borrowed handle. */ + private static PooledConnection pooledOf(Connection borrowed) { + return interceptorOf(borrowed, ProxyConnection.class).getConnection(); + } + + @Test + void borrowStoresTheBorrowSiteAndFormatsItOnlyOnFirstRead() throws Exception { + DataSource ds = newDataSource(); + ds.getPoolProperties().setLogAbandoned(true); + + Connection borrowed = ds.getConnection(); + try { + PooledConnection pooled = pooledOf(borrowed); + Assertions.assertNull(traceField(pooled, "abandonTrace"), + "a borrow with logAbandoned must not format a thread dump up front"); + StackTraceElement[] stored = + (StackTraceElement[]) traceField(pooled, "abandonTraceElements"); + Assertions.assertNotNull(stored, + "the borrow must record the borrow site, unformatted"); + + String trace = pooled.getStackTrace(); + Assertions.assertTrue(trace.startsWith("java.lang.Exception"), + "the reported text must keep the header the eager formatting produced: " + + trace.substring(0, Math.min(trace.length(), 40))); + Assertions.assertTrue(trace.contains("TestAbandonedTrace"), + "the trace must name the borrowing class"); + Assertions.assertTrue(trace.contains("borrowStoresTheBorrowSiteAndFormatsItOnlyOnFirstRead"), + "the trace must name the borrowing method"); + + // a report reads the trace twice - it logs it and notifies of + // it - and must see one and the same text both times + Assertions.assertEquals(trace, pooled.getStackTrace()); + Assertions.assertSame(trace, pooled.getStackTrace(), + "the formatted trace must be cached, not reformatted per reading"); + Assertions.assertNull(traceField(pooled, "abandonTraceElements"), + "the elements must not be kept once they have been formatted"); + } finally { + borrowed.close(); + } + } + + @Test + void anAbandonedBorrowReportsTheBorrowSiteTrace() throws Exception { + DataSource ds = newDataSource(); + PoolConfiguration properties = ds.getPoolProperties(); + properties.setName("AbandonedTrace-" + System.nanoTime()); + properties.setJmxEnabled(true); + properties.setLogAbandoned(true); + properties.setRemoveAbandoned(true); + // abandon a connection held for one second, checked four times a second + properties.setRemoveAbandonedTimeout(1); + properties.setTimeBetweenEvictionRunsMillis(250); + properties.setInitialSize(0); + ds.createPool(); + + List<Notification> abandoned = new CopyOnWriteArrayList<>(); + NotificationListener listener = (notification, handback) -> { + if (org.apache.tomcat.jdbc.pool.jmx.ConnectionPool.NOTIFY_ABANDON + .equals(notification.getType())) { + abandoned.add(notification); + } + }; + ds.getPool().getJmxPool().addListener(listener); + + // deliberately never returned: the pool is to abandon this borrow, + // whose trace was recorded unformatted at the borrow above + ds.getConnection(); + + awaitUntil(() -> !abandoned.isEmpty()); + String trace = String.valueOf(abandoned.get(0).getMessage()); + Assertions.assertTrue(trace.contains("TestAbandonedTrace"), + "the abandoned notification must carry the borrow-site trace: " + trace); + Assertions.assertTrue(trace.contains("anAbandonedBorrowReportsTheBorrowSiteTrace"), + "the abandoned notification must carry the borrowing method's frame: " + trace); + + // the abandoned connection went out of service with its session + awaitSessions(0); + } +} diff --git a/webapps/docs/changelog.xml b/webapps/docs/changelog.xml index 527d33083c..13b9c3ad68 100644 --- a/webapps/docs/changelog.xml +++ b/webapps/docs/changelog.xml @@ -1323,6 +1323,15 @@ refusal logged rather than the borrow or the return around it failed. Pull request <pr>677</pr> provided by Fernanda Meheust. (remm) </add> + <fix> + Record the borrow site of a connection borrowed from the JDBC pool + with <code>logAbandoned</code> enabled as stack trace elements + instead of a formatted thread-dump string, and format the trace only + when an abandoned-connection report actually reads it. Every borrow + previously formatted - and almost always threw away - a full thread + dump; the text reported for a connection that really is abandoned is + unchanged. Pull request <pr>1048</pr> provided by sainadh777. (remm) + </fix> </changelog> </subsection> <subsection name="Other"> --------------------------------------------------------------------- To unsubscribe, e-mail: [email protected] For additional commands, e-mail: [email protected]
