Session.close fails to close a JDBC Connection, I've found, if the first two calls to the connection (getAutoCommit and isClosed) throw SQLException and subsequent calls don't throw exceptions. This seems like a bug to me. Can you recommend a workaround?
That's unusual behavior for a Connection, but it happens. One example is a Spring TransactionAwareDataSourceProxy, with a connection pool that's temporarily exhausted. Spring attempts to get a connection from the pool on each call to a Connection method. The first two calls may fail because the pool is exhausted, but the third call may allocate a connection and succeed. Other connection pooling systems behave this way.
This creates a vicious cycle: if the pool is temporarily exhausted, Hibernate leaks a connection, which makes it more likely that the pool will become exhausted. If demand for connections doesn't stop, all the connections will leak and the pool will be permanently exhausted.
Here's a JUnit test case that shows the problem. First the output:
Code:
2010/01/08 16:17:56.242 INFO [org.hibernate.cfg.Environment] Hibernate 3.3.2.GA
2010/01/08 16:17:56.245 INFO [org.hibernate.cfg.Environment] loaded properties from resource hibernate.properties: {hibernate.dialect=org.hibernate.dialect.Oracle10gDialect, hibernate.temp.use_jdbc_metadata_defaults=false, hibernate.bytecode.use_reflection_optimizer=false, hibernate.transaction.factory_class=org.springframework.orm.hibernate3.SpringTransactionFactory, hibernate.connection.provider_class=com.linkedin.test.hibernate.MockConnectionProvider}
2010/01/08 16:17:56.247 INFO [org.hibernate.cfg.Environment] Bytecode provider name : javassist
2010/01/08 16:17:56.250 INFO [org.hibernate.cfg.Environment] using JDK 1.4 java.sql.Timestamp handling
2010/01/08 16:17:56.307 INFO [org.hibernate.connection.ConnectionProviderFactory] Initializing connection provider: com.linkedin.test.hibernate.MockConnectionProvider
2010/01/08 16:17:56.334 INFO [org.hibernate.dialect.Dialect] Using dialect: org.hibernate.dialect.Oracle10gDialect
2010/01/08 16:17:56.368 INFO [org.hibernate.transaction.TransactionFactoryFactory] Transaction strategy: org.springframework.orm.hibernate3.SpringTransactionFactory
2010/01/08 16:17:56.379 INFO [org.hibernate.transaction.TransactionManagerLookupFactory] No TransactionManagerLookup configured (in JTA environment, use of read-write or transactional second-level cache is not recommended)
2010/01/08 16:17:56.381 INFO [org.hibernate.hql.ast.ASTQueryTranslatorFactory] Using ASTQueryTranslatorFactory
2010/01/08 16:17:56.416 INFO [org.hibernate.impl.SessionFactoryImpl] building session factory
2010/01/08 16:17:56.423 INFO [org.hibernate.impl.SessionFactoryObjectFactory] Not binding factory to JNDI, no JNDI name configured
2010/01/08 16:17:56.454 DEBUG [org.hibernate.jdbc.ConnectionManager] opening JDBC connection
2010/01/08 16:17:56.488 ERROR [org.hibernate.transaction.JDBCTransaction] JDBC begin failed
java.sql.SQLException: pool exhausted
at org.easymock.internal.MockInvocationHandler.invoke(MockInvocationHandler.java:34)
at org.easymock.internal.ObjectMethodsFilter.invoke(ObjectMethodsFilter.java:61)
at $Proxy0.getAutoCommit(Unknown Source)
at org.hibernate.transaction.JDBCTransaction.begin(JDBCTransaction.java:85)
at org.hibernate.impl.SessionImpl.beginTransaction(SessionImpl.java:1354)
at com.linkedin.test.hibernate.TestConnectionManager.testBeginFailed(TestConnectionManager.java:31)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:592)
at junit.framework.TestCase.runTest(TestCase.java:154)
at junit.framework.TestCase.runBare(TestCase.java:127)
at junit.framework.TestResult$1.protect(TestResult.java:106)
at junit.framework.TestResult.runProtected(TestResult.java:124)
at junit.framework.TestResult.run(TestResult.java:109)
at junit.framework.TestCase.run(TestCase.java:118)
at junit.framework.TestSuite.runTest(TestSuite.java:208)
at junit.framework.TestSuite.run(TestSuite.java:203)
at org.eclipse.jdt.internal.junit.runner.junit3.JUnit3TestReference.run(JUnit3TestReference.java:130)
at org.eclipse.jdt.internal.junit.runner.TestExecution.run(TestExecution.java:38)
at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.runTests(RemoteTestRunner.java:460)
at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.runTests(RemoteTestRunner.java:673)
at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.run(RemoteTestRunner.java:386)
at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.main(RemoteTestRunner.java:196)
2010/01/08 16:17:56.489 TRACE [org.hibernate.jdbc.ConnectionManager] performing cleanup
2010/01/08 16:17:56.489 DEBUG [org.hibernate.jdbc.ConnectionManager] releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
2010/01/08 16:17:56.490 WARN [org.hibernate.util.JDBCExceptionReporter] SQL Error: 0, SQLState: null
2010/01/08 16:17:56.490 ERROR [org.hibernate.util.JDBCExceptionReporter] pool exhausted
2010/01/08 16:17:56.490 TRACE [org.hibernate.jdbc.JDBCContext] after transaction completion
2010/01/08 16:17:56.491 DEBUG [org.hibernate.jdbc.ConnectionManager] transaction completed on session with on_close connection release mode; be sure to close the session to release JDBC resources!
2010/01/08 16:17:56.494 ERROR [com.linkedin.test.hibernate.TestConnectionManager] java.lang.AssertionError:
Expectation failure on verify:
getAutoCommit(): expected: between 0 and 1, actual: 1
close(): expected: 1, actual: 0
2010/01/08 16:17:56.494 INFO [org.hibernate.impl.SessionFactoryImpl] closing
Here's the hibernate.properties file:
Code:
hibernate.connection.provider_class=com.linkedin.test.hibernate.MockConnectionProvider
hibernate.temp.use_jdbc_metadata_defaults=false
hibernate.dialect=org.hibernate.dialect.Oracle10gDialect
hibernate.transaction.factory_class=org.springframework.orm.hibernate3.SpringTransactionFactory
Here's the test driver:
Code:
package com.linkedin.test.hibernate;
import junit.framework.TestCase;
import org.apache.commons.logging.Log;
import org.apache.commons.logging.LogFactory;
import org.hibernate.JDBCException;
import org.hibernate.SessionFactory;
import org.hibernate.Transaction;
import org.hibernate.TransactionException;
import org.hibernate.cfg.Configuration;
import org.hibernate.classic.Session;
/**
* Test org.hibernate.jdbc.ConnectionManager.
* @author <a href="mailto:jkristian@linkedin.com">John Kristian</a>
*/
public class TestConnectionManager extends TestCase {
private static final Log log = LogFactory.getLog(TestConnectionManager.class);
public TestConnectionManager(String name) {
super(name);
}
/** Handle exceptions when beginTransaction can't get a database connection. */
public void testBeginFailed() {
SessionFactory sessionFactory = new Configuration().buildSessionFactory();
try {
Session session = sessionFactory.openSession();
try {
Transaction tx = session.beginTransaction();
tx.commit();
fail("expected TransactionException");
} catch (TransactionException expected) {
log.debug("session.beginTransaction", expected);
} finally {
try {
session.close();
fail("expected JDBCException");
} catch (JDBCException expected) {
log.debug("session.close", expected);
}
MockConnectionProvider.verify();
}
} catch (AssertionError e) {
log.error(e);
throw e;
} finally {
sessionFactory.close();
}
}
}
And the mock ConnectionProvider:
Code:
package com.linkedin.test.hibernate;
import java.lang.reflect.InvocationHandler;
import java.lang.reflect.InvocationTargetException;
import java.lang.reflect.Method;
import java.lang.reflect.Proxy;
import java.sql.Connection;
import java.sql.SQLException;
import java.util.ArrayList;
import java.util.Collection;
import java.util.Properties;
import org.apache.commons.logging.Log;
import org.apache.commons.logging.LogFactory;
import org.easymock.EasyMock;
import org.easymock.IAnswer;
import org.hibernate.HibernateException;
import org.hibernate.connection.ConnectionProvider;
/**
* Simulates a connection pool that's temporarily exhausted.
* @author <a href="mailto:jkristian@linkedin.com">John Kristian</a>
*/
public class MockConnectionProvider implements ConnectionProvider {
private static final Log log = LogFactory.getLog(MockConnectionProvider.class);
private static final Collection<Object> mocks = new ArrayList<Object>();
public void configure(Properties props) throws HibernateException {
}
public boolean supportsAggressiveRelease() {
return true;
}
public Connection getConnection() throws SQLException {
SQLException poolExhausted = new SQLException("pool exhausted");
Connection connection = EasyMock.createStrictMock(Connection.class);
EasyMock.expect(connection.getAutoCommit()).andThrow(poolExhausted);
{
// This works: EasyMock.expect(connection.isClosed()).andReturn(true);
// This works: EasyMock.expect(connection.isClosed()).andReturn(false);
// But this causes a leak:
EasyMock.expect(connection.isClosed()).andThrow(poolExhausted);
EasyMock.expect(connection.isClosed()).andReturn(false);
}
EasyMock.expect(connection.getAutoCommit()).andAnswer(new LogStackAndReturn<Boolean>(false)).times(0, 1);
// EasyMock.expect(connection.getWarnings()).andReturn(null).times(0, 1);
// connection.clearWarnings(); EasyMock.expectLastCall().times(0, 1);
connection.close(); EasyMock.expectLastCall();
EasyMock.replay(connection);
mocks.add(connection);
if (log.isTraceEnabled()) {
connection = (Connection) Proxy.newProxyInstance(connection.getClass().getClassLoader(),
new Class[] { Connection.class }, new LogCall(connection));
}
return connection;
}
public void closeConnection(Connection connection) throws SQLException {
connection.close();
}
public void close() throws HibernateException {
log.trace("close");
}
public static void verify() {
EasyMock.verify(mocks.toArray());
}
/** Logs the current stack and then returns a given value. */
private static class LogStackAndReturn<T> implements IAnswer<T> {
private final T _answer;
LogStackAndReturn(T answer) {
_answer = answer;
}
public T answer() throws Throwable {
log.debug("stack trace", new Exception());
return _answer;
}
}
/** Logs the method name and the returned value. */
private static class LogCall implements InvocationHandler {
private final Object _subject;
LogCall(Object subject) {
_subject = subject;
}
public Object invoke(Object proxy, Method method, Object[] args) throws Throwable {
String name = method.getName();
log.trace("-> " + name);
String valediction = "<- " + name + " ";
try {
Object result = method.invoke(_subject, args);
valediction += "returned " + result;
return result;
} catch (InvocationTargetException e) {
Throwable t = e.getCause();
valediction += "threw " + t;
throw t;
} catch (Throwable t) {
valediction += "threw " + t;
throw t;
} finally {
log.trace(valediction);
}
}
}
}
Login
FAQ
Search