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 17fed49bf99b1aeed6cfb4525258c91eddfc4fd2 Author: opencode <[email protected]> AuthorDate: Thu Nov 5 16:50:05 2026 +0100 Sanitize SQL newlines in StatementCache log messages StatementCache interpolated getSql() directly into its discarded-statement warning and lost-association debug line. SQL is application- and user-shaped data and JULI does not escape message newlines, so embedded CR/LF could forge additional log lines. Add sqlForLog() to replace CR/LF with spaces and use it at all three SQL log sites. Add a log-capture test that parks a statement whose SQL contains newlines and asserts the warning stays on one readable line. --- .../jdbc/pool/interceptor/StatementCache.java | 30 +++++++-- .../TestStatementCachePurgeCloseFailure.java | 72 ++++++++++++++++++++++ 2 files changed, 97 insertions(+), 5 deletions(-) diff --git a/modules/jdbc-pool/src/main/java/org/apache/tomcat/jdbc/pool/interceptor/StatementCache.java b/modules/jdbc-pool/src/main/java/org/apache/tomcat/jdbc/pool/interceptor/StatementCache.java index 2598a80d17..1a7ba2a949 100644 --- a/modules/jdbc-pool/src/main/java/org/apache/tomcat/jdbc/pool/interceptor/StatementCache.java +++ b/modules/jdbc-pool/src/main/java/org/apache/tomcat/jdbc/pool/interceptor/StatementCache.java @@ -59,7 +59,8 @@ import org.apache.tomcat.jdbc.pool.util.MessageFactory; * that closes tracked statements at the connection return is affected too: {@link StatementFinalizer} must be listed * before this one, because a parked statement is deliberately left open and a tracker beneath the cache would close * it out from under a live cache entry; listed after this one, it makes this cache refuse to park at all, and - * statements are closed normally instead of cached. + * statements are closed normally instead of cached. Only {@link StatementFinalizer} and its subclasses are recognised + * by that check; a third-party interceptor with the same behaviour is not detected. */ public class StatementCache extends StatementDecoratorInterceptor implements StatementCacheMBean { private static final Log log = LogFactory.getLog(StatementCache.class); @@ -135,7 +136,7 @@ public class StatementCache extends StatementDecoratorInterceptor implements Sta * A copy is returned because the arrays a cache matches against are shared * by every instance in the class loader; mutating the array behind the * accessor would change what every pool in the JVM caches, not just this - * one. + * one. This is an extension accessor: the pool itself does not read it. * * @return array of statement type strings */ @@ -558,6 +559,25 @@ public class StatementCache extends StatementDecoratorInterceptor implements Sta */ private final AtomicBoolean associationLossLogged = new AtomicBoolean(); + /** + * Renders SQL text for interpolation into a log message. JULI writes message text without newline escaping, and + * SQL is application- and user-shaped data, so embedded CR/LF would forge additional log lines. They are replaced + * by spaces, keeping the statement readable in the one line the log entry owns. + * + * @param sql the SQL text, possibly null + * + * @return the text safe to interpolate into a log message + */ + private static String sqlForLog(String sql) { + if (sql == null) { + return "null"; + } + if (sql.indexOf('\r') < 0 && sql.indexOf('\n') < 0) { + return sql; + } + return sql.replace('\r', ' ').replace('\n', ' '); + } + /** * Logs, at most once per connection, that a park was refused because the connection recorded for the statement * is not the current physical one. The usual cause is benign - a close racing a session replacement - but a @@ -572,7 +592,7 @@ public class StatementCache extends StatementDecoratorInterceptor implements Sta // not spend the claim, and the compare-and-set runs second, so of the // refusals met while debug is on exactly one logs. if (log.isDebugEnabled() && associationLossLogged.compareAndSet(false, true)) { - log.debug("Not caching statement [" + proxy.getSql() + "]: the connection recorded for it is " + log.debug("Not caching statement [" + sqlForLog(proxy.getSql()) + "]: the connection recorded for it is " + "not the current physical connection. Either the session was replaced while the " + "statement was being closed, or an interceptor listed below " + getClass().getSimpleName() + " answers the statement's getConnection() with a value " @@ -779,7 +799,7 @@ public class StatementCache extends StatementDecoratorInterceptor implements Sta ExceptionUtils.handleThrowable(x); removeStatement(proxy); if (log.isDebugEnabled()) { - log.debug("Unable to recycle statement: " + getSql(), x); + log.debug("Unable to recycle statement: " + sqlForLog(getSql()), x); } } } @@ -822,7 +842,7 @@ public class StatementCache extends StatementDecoratorInterceptor implements Sta // A non-fatal Error from the driver's close is a failed close // here, not a reason to abort the remainder of the purge. ExceptionUtils.handleThrowable(x); - log.warn(MessageFactory.get("statementCache.unableToCloseDiscardedStatement", getSql()), x); + log.warn(MessageFactory.get("statementCache.unableToCloseDiscardedStatement", sqlForLog(getSql())), x); } } diff --git a/modules/jdbc-pool/src/test/java/org/apache/tomcat/jdbc/pool/interceptor/TestStatementCachePurgeCloseFailure.java b/modules/jdbc-pool/src/test/java/org/apache/tomcat/jdbc/pool/interceptor/TestStatementCachePurgeCloseFailure.java index 9c8516561b..22c1a12ff2 100644 --- a/modules/jdbc-pool/src/test/java/org/apache/tomcat/jdbc/pool/interceptor/TestStatementCachePurgeCloseFailure.java +++ b/modules/jdbc-pool/src/test/java/org/apache/tomcat/jdbc/pool/interceptor/TestStatementCachePurgeCloseFailure.java @@ -23,7 +23,14 @@ import java.lang.reflect.Proxy; import java.sql.Connection; import java.sql.PreparedStatement; import java.sql.Statement; +import java.util.ArrayList; +import java.util.Collections; +import java.util.List; import java.util.concurrent.atomic.AtomicBoolean; +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; @@ -114,4 +121,69 @@ class TestStatementCachePurgeCloseFailure extends JdbcPoolBaseTest { shared.close(); } } + + @Test + void theDiscardedStatementLogSanitizesNewlines() throws Exception { + DataSource ds = newDataSource(); + ds.getPoolProperties().setJdbcInterceptors( + ErrorCloseStatementCache.class.getName() + "(prepared=true,max=5)"); + ds.getPoolProperties().setMaxActive(1); + ds.getPoolProperties().setTimeBetweenEvictionRunsMillis(60000); + ds.createPool(); + + Connection shared = ds.getConnection(); + try { + ErrorCloseStatementCache cache = + interceptorOf(shared, ErrorCloseStatementCache.class); + PooledConnection pcon = (PooledConnection) shared.unwrap(PooledConnection.class); + FAIL_NEXT_CLOSE.set(true); + PreparedStatement statement = shared.prepareStatement( + "SELECT 1\nFROM SYSTEM_RANGE(1,1)\r"); + statement.close(); + + Logger logger = Logger.getLogger(StatementCache.class.getName()); + Level originalLevel = logger.getLevel(); + List<LogRecord> records = Collections.synchronizedList(new ArrayList<>()); + 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 + } + }; + logger.addHandler(handler); + logger.setLevel(Level.ALL); + try { + cache.disconnected(ds.getPool(), pcon, false); + } finally { + logger.removeHandler(handler); + logger.setLevel(originalLevel); + } + + LogRecord reported = null; + for (LogRecord record : records) { + if (record.getMessage() != null + && record.getMessage().contains("that the statement cache is discarding")) { + reported = record; + } + } + Assertions.assertNotNull(reported, "the failing close must be reported"); + Assertions.assertFalse(reported.getMessage().contains("\n") + || reported.getMessage().contains("\r"), + "the SQL in the log must not carry newlines: " + reported.getMessage()); + Assertions.assertTrue(reported.getMessage().contains("SELECT 1 FROM SYSTEM_RANGE(1,1)"), + "the SQL must stay readable in one line: " + reported.getMessage()); + } finally { + shared.close(); + } + } } --------------------------------------------------------------------- To unsubscribe, e-mail: [email protected] For additional commands, e-mail: [email protected]
