From 152fe0a17720c53ad3598661dbab9385164294a3 Mon Sep 17 00:00:00 2001 From: Roland Praml Date: Fri, 28 Feb 2025 08:04:04 +0100 Subject: [PATCH 1/4] Rollback/Commit in close if there may be an open transaction --- .../ebean/datasource/DataSourceBuilder.java | 22 ++ .../io/ebean/datasource/DataSourceConfig.java | 15 ++ .../datasource/DataSourcePoolListener.java | 5 +- ebean-datasource/pom.xml | 7 + .../ebean/datasource/pool/ConnectionPool.java | 39 ++++ .../datasource/pool/PooledConnection.java | 9 +- .../io/ebean/datasource/test/Db2Test.java | 207 ++++++++++++++++++ 7 files changed, 301 insertions(+), 3 deletions(-) create mode 100644 ebean-datasource/src/test/java/io/ebean/datasource/test/Db2Test.java diff --git a/ebean-datasource-api/src/main/java/io/ebean/datasource/DataSourceBuilder.java b/ebean-datasource-api/src/main/java/io/ebean/datasource/DataSourceBuilder.java index 89b574f..fb06c62 100644 --- a/ebean-datasource-api/src/main/java/io/ebean/datasource/DataSourceBuilder.java +++ b/ebean-datasource-api/src/main/java/io/ebean/datasource/DataSourceBuilder.java @@ -749,6 +749,28 @@ default DataSourceBuilder initDatabaseForPlatform(String platform) { */ DataSourceBuilder loadSettings(Properties properties, String poolName); + + /** + * Sets the behaviour what to do, when a connection is closed (=returned to pool), while there is uncommitted work. + *

+ * Possible values + *

+ */ + DataSourceBuilder closeWithinTxn(String closeWithinTxn); + + /** + * Returns the behaviour, what to do, when a connection is (=returned to pool), while there is uncommitted work. + *

+ * See {@link #closeWithinTxn(String)}. + */ + String closeWithinTxn(); + /** * The settings of the DataSourceBuilder. Provides getters/accessors * to read the configured properties of this DataSourceBuilder. diff --git a/ebean-datasource-api/src/main/java/io/ebean/datasource/DataSourceConfig.java b/ebean-datasource-api/src/main/java/io/ebean/datasource/DataSourceConfig.java index 21d24fc..777d826 100644 --- a/ebean-datasource-api/src/main/java/io/ebean/datasource/DataSourceConfig.java +++ b/ebean-datasource-api/src/main/java/io/ebean/datasource/DataSourceConfig.java @@ -83,6 +83,7 @@ public class DataSourceConfig implements DataSourceBuilder.Settings { private String applicationName; private boolean shutdownOnJvmExit; private boolean validateOnHeartbeat = !System.getenv().containsKey("LAMBDA_TASK_ROOT"); + private String closeWithinTxn = "rollback"; @Override public Settings settings() { @@ -144,6 +145,7 @@ public DataSourceConfig copy() { copy.initSql = initSql; copy.alert = alert; copy.listener = listener; + copy.closeWithinTxn = closeWithinTxn; return copy; } @@ -798,6 +800,8 @@ private void loadSettings(ConfigPropertiesHelper properties) { offline = properties.getBoolean("offline", offline); shutdownOnJvmExit = properties.getBoolean("shutdownOnJvmExit", shutdownOnJvmExit); validateOnHeartbeat = properties.getBoolean("validateOnHeartbeat", validateOnHeartbeat); + closeWithinTxn = properties.get("closeWithinTxn", closeWithinTxn); + String isoLevel = properties.get("isolationLevel", _isolationLevel(isolationLevel)); this.isolationLevel = _isolationLevel(isoLevel); @@ -846,6 +850,17 @@ Map parseCustom(String customProperties) { return propertyMap; } + @Override + public DataSourceBuilder closeWithinTxn(String closeWithinTxn) { + this.closeWithinTxn = closeWithinTxn; + return this; + } + + @Override + public String closeWithinTxn() { + return closeWithinTxn; + } + /** * Return the isolation level description from the associated Connection int value. */ diff --git a/ebean-datasource-api/src/main/java/io/ebean/datasource/DataSourcePoolListener.java b/ebean-datasource-api/src/main/java/io/ebean/datasource/DataSourcePoolListener.java index 555628f..5471c51 100644 --- a/ebean-datasource-api/src/main/java/io/ebean/datasource/DataSourcePoolListener.java +++ b/ebean-datasource-api/src/main/java/io/ebean/datasource/DataSourcePoolListener.java @@ -17,11 +17,12 @@ public interface DataSourcePoolListener { /** * Called after a connection has been retrieved from the connection pool */ - void onAfterBorrowConnection(Connection connection); + default void onAfterBorrowConnection(Connection connection) {} /** * Called before a connection will be put back to the connection pool */ - void onBeforeReturnConnection(Connection connection); + default void onBeforeReturnConnection(Connection connection) {} + } diff --git a/ebean-datasource/pom.xml b/ebean-datasource/pom.xml index 04a2cbc..9958cf4 100644 --- a/ebean-datasource/pom.xml +++ b/ebean-datasource/pom.xml @@ -76,6 +76,13 @@ test + + com.ibm.db2 + jcc + 11.5.9.0 + test + + diff --git a/ebean-datasource/src/main/java/io/ebean/datasource/pool/ConnectionPool.java b/ebean-datasource/src/main/java/io/ebean/datasource/pool/ConnectionPool.java index c58651f..0dd87b0 100644 --- a/ebean-datasource/src/main/java/io/ebean/datasource/pool/ConnectionPool.java +++ b/ebean-datasource/src/main/java/io/ebean/datasource/pool/ConnectionPool.java @@ -25,6 +25,10 @@ */ final class ConnectionPool implements DataSourcePool { + enum CloseWithinTxn { + NOTHING, ROLLBACK, COMMIT, FAIL, REMOVE; + } + private static final String APPLICATION_NAME = "ApplicationName"; private final ReentrantLock heartbeatLock = new ReentrantLock(false); private final ReentrantLock notifyLock = new ReentrantLock(false); @@ -55,6 +59,7 @@ final class ConnectionPool implements DataSourcePool { private final boolean failOnStart; private final int maxInactiveMillis; private final long validateStaleMillis; + private final CloseWithinTxn closeWithinTxn; /** * Max age a connection is allowed in millis. * A value of 0 means no limit (no trimming based on max age). @@ -94,6 +99,7 @@ final class ConnectionPool implements DataSourcePool { private final boolean shutdownOnJvmExit; private Thread shutdownHook; + ConnectionPool(String name, DataSourceConfig params) { this.config = params; this.name = name; @@ -128,10 +134,12 @@ final class ConnectionPool implements DataSourcePool { this.user = params.getUsername(); this.shutdownOnJvmExit = params.isShutdownOnJvmExit(); this.source = DriverDataSource.of(name, params); + this.closeWithinTxn = Enum.valueOf(CloseWithinTxn.class, params.closeWithinTxn().toUpperCase(Locale.ROOT)); if (!params.isOffline()) { init(); } this.nextTrimTime = System.currentTimeMillis() + trimPoolFreqMillis; + } private void init() { @@ -516,6 +524,37 @@ boolean invalidConnection(PooledConnection conn) { } } + /** + * Fail hard in close() when there is uncommitted work. This is for debugging to find wrong code. + */ + boolean failIfWithinTransaction() { + return closeWithinTxn == CloseWithinTxn.FAIL; + } + + /** + * will be called, before the connection is returned to the pool. This happens, when there may + * be uncommitted changes and before all settings like autocommit/schema/catalog are reset to default. + *

+ * If this method fails, the connection is silently removed from pool + */ + void closeWithinTxn(PooledConnection pooledConnection) throws SQLException { + switch (closeWithinTxn) { + case NOTHING: + Log.trace("Closing active connection."); + break; + case ROLLBACK: + pooledConnection.rollback(); + Log.trace("Closing active connection. Rollback performed."); + break; + case COMMIT: + pooledConnection.commit(); + Log.trace("Closing active connection. Commit performed."); + break; + case REMOVE: + throw new SQLException("Closing active connection. Removing from pool."); + } + } + /** * Called by the PooledConnection themselves, returning themselves to the * pool when they have been finished with. diff --git a/ebean-datasource/src/main/java/io/ebean/datasource/pool/PooledConnection.java b/ebean-datasource/src/main/java/io/ebean/datasource/pool/PooledConnection.java index 2e8185a..19e8477 100644 --- a/ebean-datasource/src/main/java/io/ebean/datasource/pool/PooledConnection.java +++ b/ebean-datasource/src/main/java/io/ebean/datasource/pool/PooledConnection.java @@ -448,6 +448,11 @@ public void close() throws SQLException { if (status == STATUS_IDLE) { throw new SQLException(IDLE_CONNECTION_ACCESSED_ERROR + "close()"); } + boolean mayHaveUncommittedChanges = !autoCommit && !readOnly && status == STATUS_ACTIVE; + if (mayHaveUncommittedChanges && pool.failIfWithinTransaction()) { + pool.returnConnectionForceClose(this); + throw new SQLException("Tried to close active connection within transaction"); + } if (hadErrors) { if (failoverToReadOnly) { pool.returnConnectionReset(this); @@ -458,12 +463,14 @@ public void close() throws SQLException { return; } } - try { if (connection.isClosed()) { pool.removeClosedConnection(this); return; } + if (mayHaveUncommittedChanges) { + pool.closeWithinTxn(this); + } // reset the autoCommit back if client code changed it if (autoCommit != pool.isAutoCommit()) { connection.setAutoCommit(pool.isAutoCommit()); diff --git a/ebean-datasource/src/test/java/io/ebean/datasource/test/Db2Test.java b/ebean-datasource/src/test/java/io/ebean/datasource/test/Db2Test.java new file mode 100644 index 0000000..08aa84c --- /dev/null +++ b/ebean-datasource/src/test/java/io/ebean/datasource/test/Db2Test.java @@ -0,0 +1,207 @@ +package io.ebean.datasource.test; + +import ch.qos.logback.classic.Level; +import ch.qos.logback.classic.spi.ILoggingEvent; +import ch.qos.logback.core.read.ListAppender; +import com.ibm.db2.jcc.DB2Connection; +import io.avaje.applog.AppLog; +import io.ebean.datasource.DataSourceBuilder; +import io.ebean.datasource.DataSourcePool; +import io.ebean.datasource.DataSourcePoolListener; +import io.ebean.test.containers.Db2Container; +import org.junit.jupiter.api.AfterAll; +import org.junit.jupiter.api.BeforeAll; +import org.junit.jupiter.api.Test; +import org.slf4j.LoggerFactory; + +import java.sql.Connection; +import java.sql.PreparedStatement; +import java.sql.SQLException; + +import static org.assertj.core.api.Assertions.assertThat; + +/** + * DB2 has a strange behaviour, when a connection is in a dirty state and neither committed nor rolled back. + *

+ * By default, a transaction cannot be closed if it is in an unit of work and an exception is thrown. + *

+ * This can be controlled with the "connectionCloseWithInFlightTransaction" parameter + * https://www.ibm.com/docs/en/db2/11.5?topic=pdsdjs-common-data-server-driver-jdbc-sqlj-properties-all-database-products + *

+ * There are several cases, when there is an open unit of work: + *

+ */ +class Db2Test { + + private static Db2Container container; + + private static ListAppender logCapture = new ListAppender<>(); + + @BeforeAll + static void before() { + container = Db2Container.builder("11.5.6.0a") + .dbName("unit") + .user("unit") + .password("unit") + // to change collation, charset and other parameters like pagesize: + .configOptions("USING CODESET UTF-8 TERRITORY DE COLLATE USING IDENTITY PAGESIZE 32768") + .configOptions("USING STRING_UNITS CODEUNITS32") + .build(); + + // container.startWithDropCreate(); + container.start(); + + // attach logback appender to capture log messages + ((ch.qos.logback.classic.Logger) LoggerFactory.getLogger("io.ebean.datasource")).addAppender(logCapture); + logCapture.start(); + } + + @AfterAll + static void after() { + // container.stopRemove(); + logCapture.stop(); + } + + @Test + void testNoCommitOrRollback() throws SQLException { + + DataSourcePool pool = getPool(); + + logCapture.list.clear(); + try { + try (Connection connection = pool.getConnection()) { + // we do nothing here. + } + } finally { + pool.shutdown(); + } + assertThat(logCapture.list.stream().filter(e -> e.getLevel().levelInt >= Level.WARN_INT)).isEmpty(); + assertThat(logCapture.list) + .extracting(ILoggingEvent::toString).contains("[TRACE] Closing active connection. Rollback performed."); + } + + + @Test + void testFalseFriendRollback() throws SQLException { + + DataSourcePool pool = getPool(); + + logCapture.list.clear(); + try { + try (Connection connection = pool.getConnection()) { + // we do a rollback here + connection.rollback(); + connection.getSchema(); // will re-open a new UOW + } + } finally { + pool.shutdown(); + } + + assertThat(logCapture.list.stream().filter(e -> e.getLevel().levelInt >= Level.WARN_INT)) + .extracting(ILoggingEvent::toString).containsExactly("[WARN] There is a DB2 UOW open!"); + assertThat(logCapture.list) + .extracting(ILoggingEvent::toString).doesNotContain("[TRACE] Closing active connection. Rollback performed."); + } + + @Test + void testProperUse() throws SQLException { + + DataSourcePool pool = getPool(); + + logCapture.list.clear(); + try { + try (Connection connection = pool.getConnection()) { + connection.commit(); + } + } finally { + pool.shutdown(); + } + + assertThat(logCapture.list.stream().filter(e -> e.getLevel().levelInt >= Level.WARN_INT)).isEmpty(); + assertThat(logCapture.list) + .extracting(ILoggingEvent::toString).doesNotContain("[TRACE] Closing active connection. Rollback performed."); + + } + + @Test + void testErrorOccured() throws SQLException { + + DataSourcePool pool = getPool(); + + logCapture.list.clear(); + try { + try (Connection connection = pool.getConnection()) { + try (PreparedStatement statement = connection.prepareStatement("i am invalid")) { + statement.execute(); + } + connection.commit(); // we will not get here + } catch (SQLException e) { + // expected + } + } finally { + pool.shutdown(); + } + + assertThat(logCapture.list.stream().filter(e -> e.getLevel().levelInt >= Level.WARN_INT)).isEmpty(); + assertThat(logCapture.list) + .extracting(ILoggingEvent::toString).contains("[TRACE] Closing active connection. Rollback performed."); + } + + + @Test + void testProperShutdownWithMissingListener() throws SQLException { + + DataSourcePool pool = DataSourceBuilder.create() + .url(container.jdbcUrl()) + .username("unit") + .password("unit") + .ownerUsername("unit") + .ownerPassword("unit") + .closeWithinTxn("rollback") + .build(); + + logCapture.list.clear(); + try { + try (Connection connection = pool.getConnection()) { + // we do a rollback here + connection.rollback(); + connection.getSchema(); + } + } finally { + pool.shutdown(); + } + + assertThat(logCapture.list.stream().filter(e -> e.getLevel().levelInt >= Level.WARN_INT)).isEmpty(); + assertThat(logCapture.list) + .extracting(ILoggingEvent::toString).doesNotContain("[TRACE] Closing active connection. Rollback performed."); + + } + + private static DataSourcePool getPool() { + return DataSourceBuilder.create() + .url(container.jdbcUrl()) + .username("unit") + .password("unit") + .ownerUsername("unit") + .ownerPassword("unit") + .closeWithinTxn("rollback") + .listener(new DataSourcePoolListener() { + @Override + public void onBeforeReturnConnection(Connection connection) { + try { + DB2Connection db2conn = connection.unwrap(DB2Connection.class); + if (db2conn.isInDB2UnitOfWork()) { + AppLog.getLogger("io.ebean.datasource").log(System.Logger.Level.WARNING, "There is a DB2 UOW open!"); + db2conn.rollback(); + } + } catch (SQLException e) { + throw new RuntimeException(e); + } + } + }) + .build(); + } +} From 19a348395bc380ce03d2e71b175811159d305aa9 Mon Sep 17 00:00:00 2001 From: Roland Praml Date: Mon, 3 Mar 2025 10:31:55 +0100 Subject: [PATCH 2/4] refactored to enforceCleanClose --- .../ebean/datasource/DataSourceBuilder.java | 25 ++- .../io/ebean/datasource/DataSourceConfig.java | 14 +- .../ebean/datasource/pool/ConnectionPool.java | 36 +--- .../datasource/pool/PooledConnection.java | 28 +-- .../pool/ConnectionPoolCloseTest.java | 175 ++++++++++++++++++ .../io/ebean/datasource/test/Db2Test.java | 64 +------ 6 files changed, 217 insertions(+), 125 deletions(-) create mode 100644 ebean-datasource/src/test/java/io/ebean/datasource/pool/ConnectionPoolCloseTest.java diff --git a/ebean-datasource-api/src/main/java/io/ebean/datasource/DataSourceBuilder.java b/ebean-datasource-api/src/main/java/io/ebean/datasource/DataSourceBuilder.java index fb06c62..501f2f2 100644 --- a/ebean-datasource-api/src/main/java/io/ebean/datasource/DataSourceBuilder.java +++ b/ebean-datasource-api/src/main/java/io/ebean/datasource/DataSourceBuilder.java @@ -751,25 +751,24 @@ default DataSourceBuilder initDatabaseForPlatform(String platform) { /** - * Sets the behaviour what to do, when a connection is closed (=returned to pool), while there is uncommitted work. + * When enabled, the datasource enforces a clean close. This means, if you close a possible dirty + * connection, that was not committed or rolled back, an exception is thrown. *

- * Possible values - *

    - *
  • nothing nothing happens
    • - *
  • rollback a rollback is performed (default)
    • - *
  • commit a commit is performed (dangerous!)
    • - *
  • remove the connection is removed from the pool (not recommended for production, connection might leak)
    • - *
  • fail an exception is thrown by close itself (for debugging, not recommended for production)
    • - *
+ * When disabled, the situation is logged as warning. + *

+ * This option has no effect on readonly or autocommit connections. + *

+ * Note: It is recommended to enable this option in tests/test systems to find possible + * programming errors. See https://github.com/ebean-orm/ebean-datasource/issues/116 for details. */ - DataSourceBuilder closeWithinTxn(String closeWithinTxn); + DataSourceBuilder enforceCleanClose(boolean enforceCleanClose); /** - * Returns the behaviour, what to do, when a connection is (=returned to pool), while there is uncommitted work. + * When true, an exception is thrown when a dirty connection is closed. *

- * See {@link #closeWithinTxn(String)}. + * See {@link #enforceCleanClose(boolean)}. */ - String closeWithinTxn(); + boolean enforceCleanClose(); /** * The settings of the DataSourceBuilder. Provides getters/accessors diff --git a/ebean-datasource-api/src/main/java/io/ebean/datasource/DataSourceConfig.java b/ebean-datasource-api/src/main/java/io/ebean/datasource/DataSourceConfig.java index 777d826..0320e6f 100644 --- a/ebean-datasource-api/src/main/java/io/ebean/datasource/DataSourceConfig.java +++ b/ebean-datasource-api/src/main/java/io/ebean/datasource/DataSourceConfig.java @@ -83,7 +83,7 @@ public class DataSourceConfig implements DataSourceBuilder.Settings { private String applicationName; private boolean shutdownOnJvmExit; private boolean validateOnHeartbeat = !System.getenv().containsKey("LAMBDA_TASK_ROOT"); - private String closeWithinTxn = "rollback"; + private boolean enforceCleanClose; @Override public Settings settings() { @@ -145,7 +145,7 @@ public DataSourceConfig copy() { copy.initSql = initSql; copy.alert = alert; copy.listener = listener; - copy.closeWithinTxn = closeWithinTxn; + copy.enforceCleanClose = enforceCleanClose; return copy; } @@ -800,7 +800,7 @@ private void loadSettings(ConfigPropertiesHelper properties) { offline = properties.getBoolean("offline", offline); shutdownOnJvmExit = properties.getBoolean("shutdownOnJvmExit", shutdownOnJvmExit); validateOnHeartbeat = properties.getBoolean("validateOnHeartbeat", validateOnHeartbeat); - closeWithinTxn = properties.get("closeWithinTxn", closeWithinTxn); + enforceCleanClose = properties.getBoolean("enforceCleanClose", enforceCleanClose); String isoLevel = properties.get("isolationLevel", _isolationLevel(isolationLevel)); @@ -851,14 +851,14 @@ Map parseCustom(String customProperties) { } @Override - public DataSourceBuilder closeWithinTxn(String closeWithinTxn) { - this.closeWithinTxn = closeWithinTxn; + public DataSourceBuilder enforceCleanClose(boolean enforceCleanClose) { + this.enforceCleanClose = enforceCleanClose; return this; } @Override - public String closeWithinTxn() { - return closeWithinTxn; + public boolean enforceCleanClose() { + return enforceCleanClose; } /** diff --git a/ebean-datasource/src/main/java/io/ebean/datasource/pool/ConnectionPool.java b/ebean-datasource/src/main/java/io/ebean/datasource/pool/ConnectionPool.java index 0dd87b0..a1e177d 100644 --- a/ebean-datasource/src/main/java/io/ebean/datasource/pool/ConnectionPool.java +++ b/ebean-datasource/src/main/java/io/ebean/datasource/pool/ConnectionPool.java @@ -25,10 +25,6 @@ */ final class ConnectionPool implements DataSourcePool { - enum CloseWithinTxn { - NOTHING, ROLLBACK, COMMIT, FAIL, REMOVE; - } - private static final String APPLICATION_NAME = "ApplicationName"; private final ReentrantLock heartbeatLock = new ReentrantLock(false); private final ReentrantLock notifyLock = new ReentrantLock(false); @@ -59,7 +55,7 @@ enum CloseWithinTxn { private final boolean failOnStart; private final int maxInactiveMillis; private final long validateStaleMillis; - private final CloseWithinTxn closeWithinTxn; + private final boolean enforceCleanClose; /** * Max age a connection is allowed in millis. * A value of 0 means no limit (no trimming based on max age). @@ -134,7 +130,7 @@ enum CloseWithinTxn { this.user = params.getUsername(); this.shutdownOnJvmExit = params.isShutdownOnJvmExit(); this.source = DriverDataSource.of(name, params); - this.closeWithinTxn = Enum.valueOf(CloseWithinTxn.class, params.closeWithinTxn().toUpperCase(Locale.ROOT)); + this.enforceCleanClose = params.enforceCleanClose(); if (!params.isOffline()) { init(); } @@ -527,32 +523,8 @@ boolean invalidConnection(PooledConnection conn) { /** * Fail hard in close() when there is uncommitted work. This is for debugging to find wrong code. */ - boolean failIfWithinTransaction() { - return closeWithinTxn == CloseWithinTxn.FAIL; - } - - /** - * will be called, before the connection is returned to the pool. This happens, when there may - * be uncommitted changes and before all settings like autocommit/schema/catalog are reset to default. - *

- * If this method fails, the connection is silently removed from pool - */ - void closeWithinTxn(PooledConnection pooledConnection) throws SQLException { - switch (closeWithinTxn) { - case NOTHING: - Log.trace("Closing active connection."); - break; - case ROLLBACK: - pooledConnection.rollback(); - Log.trace("Closing active connection. Rollback performed."); - break; - case COMMIT: - pooledConnection.commit(); - Log.trace("Closing active connection. Commit performed."); - break; - case REMOVE: - throw new SQLException("Closing active connection. Removing from pool."); - } + boolean enforceCleanClose() { + return enforceCleanClose; } /** diff --git a/ebean-datasource/src/main/java/io/ebean/datasource/pool/PooledConnection.java b/ebean-datasource/src/main/java/io/ebean/datasource/pool/PooledConnection.java index 19e8477..84327a4 100644 --- a/ebean-datasource/src/main/java/io/ebean/datasource/pool/PooledConnection.java +++ b/ebean-datasource/src/main/java/io/ebean/datasource/pool/PooledConnection.java @@ -219,7 +219,7 @@ String description() { } String fullDescription() { - return "name[" + name + "] startTime[" + startUseTime() + "] busySeconds[" + busySeconds() + "] stackTrace[" + stackTraceAsString() + "] stmt[" + lastStatement() + "]"; + return "name[" + name + "] startTime[" + startUseTime() + "] busySeconds[" + busySeconds() + "] stackTrace[" + stackTraceAsString(stackTrace) + "] stmt[" + lastStatement() + "]"; } /** @@ -449,9 +449,9 @@ public void close() throws SQLException { throw new SQLException(IDLE_CONNECTION_ACCESSED_ERROR + "close()"); } boolean mayHaveUncommittedChanges = !autoCommit && !readOnly && status == STATUS_ACTIVE; - if (mayHaveUncommittedChanges && pool.failIfWithinTransaction()) { + if (mayHaveUncommittedChanges && pool.enforceCleanClose()) { pool.returnConnectionForceClose(this); - throw new SQLException("Tried to close active connection within transaction"); + throw new AssertionError("Tried to close a dirty connection. See https://github.com/ebean-orm/ebean-datasource/issues/116 for details."); } if (hadErrors) { if (failoverToReadOnly) { @@ -469,7 +469,9 @@ public void close() throws SQLException { return; } if (mayHaveUncommittedChanges) { - pool.closeWithinTxn(this); + Log.warn("Tried to close a dirty connection at {0}. See https://github.com/ebean-orm/ebean-datasource/issues/116 for details.", + stackTraceAsString(Thread.currentThread().getStackTrace())); + connection.rollback(); } // reset the autoCommit back if client code changed it if (autoCommit != pool.isAutoCommit()) { @@ -949,35 +951,23 @@ void setStackTrace(StackTraceElement[] stackTrace) { /** * Return the stackTrace as a String for logging purposes. */ - private String stackTraceAsString() { - StackTraceElement[] stackTrace = stackTrace(); + private String stackTraceAsString(StackTraceElement[] stackTrace) { if (stackTrace == null) { return ""; } - return Arrays.toString(stackTrace); - } - - /** - * Return the full stack trace that got the connection from the pool. You - * could use this if getCreatedByMethod() doesn't work for you. - */ - private StackTraceElement[] stackTrace() { - if (stackTrace == null) { - return null; - } // filter off the top of the stack that we are not interested in ArrayList filteredList = new ArrayList<>(); boolean include = false; for (StackTraceElement stackTraceElement : stackTrace) { - if (!include && includeMethodLine(stackTraceElement.toString())) { + if (!include && includeMethodLine(stackTraceElement.getClassName())) { include = true; } if (include && filteredList.size() < maxStackTrace) { filteredList.add(stackTraceElement); } } - return filteredList.toArray(new StackTraceElement[0]); + return filteredList.toString(); } } diff --git a/ebean-datasource/src/test/java/io/ebean/datasource/pool/ConnectionPoolCloseTest.java b/ebean-datasource/src/test/java/io/ebean/datasource/pool/ConnectionPoolCloseTest.java new file mode 100644 index 0000000..7b37969 --- /dev/null +++ b/ebean-datasource/src/test/java/io/ebean/datasource/pool/ConnectionPoolCloseTest.java @@ -0,0 +1,175 @@ +package io.ebean.datasource.pool; + +import ch.qos.logback.classic.Level; +import ch.qos.logback.classic.spi.ILoggingEvent; +import ch.qos.logback.core.read.ListAppender; +import io.ebean.datasource.DataSourceBuilder; +import io.ebean.datasource.DataSourcePool; +import org.junit.jupiter.api.AfterAll; +import org.junit.jupiter.api.BeforeAll; +import org.junit.jupiter.api.BeforeEach; +import org.junit.jupiter.api.Test; +import org.slf4j.LoggerFactory; + +import java.sql.Connection; +import java.sql.SQLException; +import java.sql.SQLSyntaxErrorException; +import java.util.List; +import java.util.stream.Collectors; + +import static org.assertj.core.api.Assertions.assertThat; +import static org.assertj.core.api.Assertions.assertThatThrownBy; + +/** + * Tests, if connections are clean when closing them. + *

+ * Test must run with "do not use module path" option in IntelliJ. + *

+ * See also https://github.com/ebean-orm/ebean-datasource/issues/116 for more details + */ +class ConnectionPoolCloseTest { + + private static ListAppender logCapture = new ListAppender<>(); + + private static DataSourcePool pool = createPool(false, false); + private static DataSourcePool poolRo = createPool(false, true); + private static DataSourcePool poolEnforce = createPool(true, false); + private static DataSourcePool poolEnforceRo = createPool(true, true); + + + @BeforeAll + static void before() { + // attach logback appender to capture log messages + ((ch.qos.logback.classic.Logger) LoggerFactory.getLogger("io.ebean.datasource")).addAppender(logCapture); + logCapture.start(); + } + + @BeforeEach + void beforeEach() { + logCapture.list.clear(); + } + + @AfterAll + static void after() { + logCapture.stop(); + pool.shutdown(); + poolRo.shutdown(); + poolEnforce.shutdown(); + poolEnforceRo.shutdown(); + } + + @Test + void testNoCommitOrRollback() throws SQLException { + + doNoCommitOrRollback(pool); + assertThat(getAndResetLogWarinings()) + .hasSize(1) + .first().asString().startsWith("[WARN] Tried to close a dirty connection at"); + + assertThatThrownBy(() -> doNoCommitOrRollback(poolEnforce)).isInstanceOf(AssertionError.class); + + doNoCommitOrRollback(poolRo); + assertThat(getAndResetLogWarinings()).isEmpty(); + + doNoCommitOrRollback(poolEnforceRo); + assertThat(getAndResetLogWarinings()).isEmpty(); + + } + + @Test + void testCommit() throws SQLException { + doCommit(pool); + doCommit(poolRo); + doCommit(poolEnforce); + doCommit(poolEnforceRo); + assertThat(getAndResetLogWarinings()).isEmpty(); + } + + @Test + void testRollback() throws SQLException { + doRollback(pool); + doRollback(poolRo); + doRollback(poolEnforce); + doRollback(poolEnforceRo); + assertThat(getAndResetLogWarinings()).isEmpty(); + } + + @Test + void testExecuteValidSql() throws SQLException { + doExecute(pool, "SELECT 1"); + doExecute(poolRo, "SELECT 1"); + doExecute(poolEnforce, "SELECT 1"); + doExecute(poolEnforceRo, "SELECT 1"); + assertThat(getAndResetLogWarinings()).isEmpty(); + } + + @Test + void testExecuteInvalidSql() throws SQLException { + assertThatThrownBy(() -> doExecute(pool, "invalid query")) + .isInstanceOf(SQLSyntaxErrorException.class) + .hasNoSuppressedExceptions(); + // (un)fortunately, we will log a missing rollback, when exception in try-with-resourches is thrown. + assertThat(getAndResetLogWarinings()) + .hasSize(1) + .first().asString().startsWith("[WARN] Tried to close a dirty connection at"); + + assertThatThrownBy(() -> doExecute(poolEnforce, "invalid query")) + .isInstanceOf(SQLSyntaxErrorException.class) + .hasSuppressedException(new AssertionError("Tried to close a dirty connection. See https://github.com/ebean-orm/ebean-datasource/issues/116 for details.")); + + assertThatThrownBy(() -> doExecute(poolRo, "invalid query")) + .isInstanceOf(SQLSyntaxErrorException.class) + .hasNoSuppressedExceptions(); + + assertThatThrownBy(() -> doExecute(poolEnforceRo, "invalid query")) + .isInstanceOf(SQLSyntaxErrorException.class) + .hasNoSuppressedExceptions(); + assertThat(getAndResetLogWarinings()).isEmpty(); + } + + private static void doNoCommitOrRollback(DataSourcePool pool) throws SQLException { + try (Connection connection = pool.getConnection()) { + // we do nothing here. + } + } + + private static void doCommit(DataSourcePool pool) throws SQLException { + try (Connection connection = pool.getConnection()) { + connection.commit(); + } + } + + private static void doRollback(DataSourcePool pool) throws SQLException { + try (Connection connection = pool.getConnection()) { + connection.rollback(); + } + } + + private static void doExecute(DataSourcePool pool, String query) throws SQLException { + try (Connection connection = pool.getConnection()) { + connection.createStatement().execute(query); + connection.commit(); + } + } + + private static List getAndResetLogWarinings() { + List warnings = logCapture.list.stream().filter(e -> e.getLevel().levelInt >= Level.WARN_INT).collect(Collectors.toList()); + logCapture.list.clear(); + return warnings; + } + + private static DataSourcePool createPool(boolean enforceCleanClose, boolean readOnly) { + DataSourcePool ret = DataSourceBuilder.create() + .url("jdbc:h2:mem:tests") + .username("sa") + .password("") + .minConnections(2) + .maxConnections(4) + .enforceCleanClose(enforceCleanClose) + .readOnly(readOnly) + .build(); + // clear capturer after create + logCapture.list.clear(); + return ret; + } +} diff --git a/ebean-datasource/src/test/java/io/ebean/datasource/test/Db2Test.java b/ebean-datasource/src/test/java/io/ebean/datasource/test/Db2Test.java index 08aa84c..4fb68d5 100644 --- a/ebean-datasource/src/test/java/io/ebean/datasource/test/Db2Test.java +++ b/ebean-datasource/src/test/java/io/ebean/datasource/test/Db2Test.java @@ -11,6 +11,7 @@ import io.ebean.test.containers.Db2Container; import org.junit.jupiter.api.AfterAll; import org.junit.jupiter.api.BeforeAll; +import org.junit.jupiter.api.Disabled; import org.junit.jupiter.api.Test; import org.slf4j.LoggerFactory; @@ -21,9 +22,9 @@ import static org.assertj.core.api.Assertions.assertThat; /** - * DB2 has a strange behaviour, when a connection is in a dirty state and neither committed nor rolled back. + * DB2 has a strange, but API-compliant behaviour, when a connection is in a dirty state and neither committed nor rolled back. *

- * By default, a transaction cannot be closed if it is in an unit of work and an exception is thrown. + * By default, a DB2-connection cannot be closed if it is in a unit of work (=transaction) and an exception is thrown. *

* This can be controlled with the "connectionCloseWithInFlightTransaction" parameter * https://www.ibm.com/docs/en/db2/11.5?topic=pdsdjs-common-data-server-driver-jdbc-sqlj-properties-all-database-products @@ -33,7 +34,10 @@ *

  • forget commit/rollback before closing the connection, because an exception occurs
    • *
  • calling connection.getSchema() starts a new UOW (because it internally executes a query)
    • * + *

    + * See also https://github.com/ebean-orm/ebean-datasource/issues/116 for more details */ +@Disabled("DB2 container start is slow - run manually") class Db2Test { private static Db2Container container; @@ -51,7 +55,6 @@ static void before() { .configOptions("USING STRING_UNITS CODEUNITS32") .build(); - // container.startWithDropCreate(); container.start(); // attach logback appender to capture log messages @@ -61,29 +64,9 @@ static void before() { @AfterAll static void after() { - // container.stopRemove(); logCapture.stop(); } - @Test - void testNoCommitOrRollback() throws SQLException { - - DataSourcePool pool = getPool(); - - logCapture.list.clear(); - try { - try (Connection connection = pool.getConnection()) { - // we do nothing here. - } - } finally { - pool.shutdown(); - } - assertThat(logCapture.list.stream().filter(e -> e.getLevel().levelInt >= Level.WARN_INT)).isEmpty(); - assertThat(logCapture.list) - .extracting(ILoggingEvent::toString).contains("[TRACE] Closing active connection. Rollback performed."); - } - - @Test void testFalseFriendRollback() throws SQLException { @@ -102,28 +85,6 @@ void testFalseFriendRollback() throws SQLException { assertThat(logCapture.list.stream().filter(e -> e.getLevel().levelInt >= Level.WARN_INT)) .extracting(ILoggingEvent::toString).containsExactly("[WARN] There is a DB2 UOW open!"); - assertThat(logCapture.list) - .extracting(ILoggingEvent::toString).doesNotContain("[TRACE] Closing active connection. Rollback performed."); - } - - @Test - void testProperUse() throws SQLException { - - DataSourcePool pool = getPool(); - - logCapture.list.clear(); - try { - try (Connection connection = pool.getConnection()) { - connection.commit(); - } - } finally { - pool.shutdown(); - } - - assertThat(logCapture.list.stream().filter(e -> e.getLevel().levelInt >= Level.WARN_INT)).isEmpty(); - assertThat(logCapture.list) - .extracting(ILoggingEvent::toString).doesNotContain("[TRACE] Closing active connection. Rollback performed."); - } @Test @@ -145,9 +106,9 @@ void testErrorOccured() throws SQLException { pool.shutdown(); } - assertThat(logCapture.list.stream().filter(e -> e.getLevel().levelInt >= Level.WARN_INT)).isEmpty(); - assertThat(logCapture.list) - .extracting(ILoggingEvent::toString).contains("[TRACE] Closing active connection. Rollback performed."); + assertThat(logCapture.list.stream().filter(e -> e.getLevel().levelInt >= Level.WARN_INT)) + .hasSize(1) + .first().asString().startsWith("[WARN] Tried to close a dirty connection at"); } @@ -160,7 +121,6 @@ void testProperShutdownWithMissingListener() throws SQLException { .password("unit") .ownerUsername("unit") .ownerPassword("unit") - .closeWithinTxn("rollback") .build(); logCapture.list.clear(); @@ -173,11 +133,8 @@ void testProperShutdownWithMissingListener() throws SQLException { } finally { pool.shutdown(); } - + // when shuttind down the pool, a rollback will be performed on all connections. assertThat(logCapture.list.stream().filter(e -> e.getLevel().levelInt >= Level.WARN_INT)).isEmpty(); - assertThat(logCapture.list) - .extracting(ILoggingEvent::toString).doesNotContain("[TRACE] Closing active connection. Rollback performed."); - } private static DataSourcePool getPool() { @@ -187,7 +144,6 @@ private static DataSourcePool getPool() { .password("unit") .ownerUsername("unit") .ownerPassword("unit") - .closeWithinTxn("rollback") .listener(new DataSourcePoolListener() { @Override public void onBeforeReturnConnection(Connection connection) { From a75a1d00ab6c5c9a367fdc5b673891db714ab8bc Mon Sep 17 00:00:00 2001 From: Roland Praml Date: Mon, 3 Mar 2025 10:35:55 +0100 Subject: [PATCH 3/4] updated cache --- .github/workflows/build.yml | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/.github/workflows/build.yml b/.github/workflows/build.yml index bc82e55..1f5c33e 100644 --- a/.github/workflows/build.yml +++ b/.github/workflows/build.yml @@ -24,7 +24,7 @@ jobs: java-version: ${{ matrix.java_version }} distribution: 'zulu' - name: Maven cache - uses: actions/cache@v2 + uses: actions/cache@v4 env: cache-name: maven-cache with: From 6d9c0ab098e954dd3b0a4a9e0fec0d1decab0e7e Mon Sep 17 00:00:00 2001 From: Roland Praml Date: Mon, 3 Mar 2025 11:06:28 +0100 Subject: [PATCH 4/4] tidy up some newlines --- .../src/main/java/io/ebean/datasource/pool/ConnectionPool.java | 2 -- .../main/java/io/ebean/datasource/pool/PooledConnection.java | 1 + 2 files changed, 1 insertion(+), 2 deletions(-) diff --git a/ebean-datasource/src/main/java/io/ebean/datasource/pool/ConnectionPool.java b/ebean-datasource/src/main/java/io/ebean/datasource/pool/ConnectionPool.java index a1e177d..d2891aa 100644 --- a/ebean-datasource/src/main/java/io/ebean/datasource/pool/ConnectionPool.java +++ b/ebean-datasource/src/main/java/io/ebean/datasource/pool/ConnectionPool.java @@ -95,7 +95,6 @@ final class ConnectionPool implements DataSourcePool { private final boolean shutdownOnJvmExit; private Thread shutdownHook; - ConnectionPool(String name, DataSourceConfig params) { this.config = params; this.name = name; @@ -135,7 +134,6 @@ final class ConnectionPool implements DataSourcePool { init(); } this.nextTrimTime = System.currentTimeMillis() + trimPoolFreqMillis; - } private void init() { diff --git a/ebean-datasource/src/main/java/io/ebean/datasource/pool/PooledConnection.java b/ebean-datasource/src/main/java/io/ebean/datasource/pool/PooledConnection.java index 84327a4..dac098b 100644 --- a/ebean-datasource/src/main/java/io/ebean/datasource/pool/PooledConnection.java +++ b/ebean-datasource/src/main/java/io/ebean/datasource/pool/PooledConnection.java @@ -463,6 +463,7 @@ public void close() throws SQLException { return; } } + try { if (connection.isClosed()) { pool.removeClosedConnection(this);