Hello,
Basically, if I do (pseudo-code, working test case below):
Code:
openSession();
t = beginTransaction();
rs = createSQLQuery.scroll();
while (rs.next()) {
// do stuff with rs.get()
t.commit();
t.beginTransaction();
}
Then, depending on which connection pool I use:
- default hibernate pool: it works fine
- Proxool or c3p0: an exception is thrown at the "next()" which
is called _after_ the commit()/beginTransaction()
Obviously, the commit/begin closes the result set I'm still using.
Therefore, a few questions:
- do I understand correctly (from looking at the debug output, below) that the connection is returned to the pool at commit time, and it is at that time "cleansed" of any pending statements/resultsets
- is my usage just plainly wrong, and the fact that it worked with the builtin pool is just a consequence of it being broken?
- is it possible to somehow force the pool not to return the connection to the pool at commit, so that I do not need to make possibly many changes to the code?
Please note this is a very simplified test case. Obviously in the real code
I do not try to make so tiny transactions, I commit every several
thousand rows or so (due to RDBMS tablespace limitations which make
it impossible to do everything in a single transaction).
Hibernate version: 3.1.3
C3P0 version: 0.9.1-pre6
Proxool version: 0.9.0RC2
Mapping documents: none, just a single table is used with SQLQuery:
CREATE TABLE A ( A NUMBER(22) );
It contains just four rows, with non-null values
The test case:Code:
package uk.co.grs.c3p0test;
import org.apache.log4j.Logger;
import org.hibernate.Hibernate;
import org.hibernate.HibernateException;
import org.hibernate.ScrollableResults;
import org.hibernate.Session;
import org.hibernate.SessionFactory;
import org.hibernate.Transaction;
import org.hibernate.cfg.Configuration;
import junit.framework.TestCase;
public class ATest extends TestCase {
private static final Logger logger = Logger.getLogger(ATest.class);
private void doTestBuiltinCacheTransaction(String file, boolean doCommit)
throws Exception
{
logger.info("Testing with pool settings from ["+file+"].");
logger.debug("Obtaining session");
Configuration cfg = new Configuration();
cfg.configure(file);
SessionFactory f = cfg.buildSessionFactory();
Session s = f.openSession();
try {
logger.info("Opening transaction");
Transaction t = s.beginTransaction();
logger.info("Running query");
ScrollableResults r = s
.createSQLQuery("select a from a")
.addScalar("a", Hibernate.LONG)
.setCacheable(false)
.scroll();
logger.info("Iterating...");
int i = 0;
while (r.next()) {
Long a = r.getLong(0);
logger.info("Got ["+a+"]");
// Do stuff
if (doCommit && i == 1) {
logger.info("Commiting transaction.");
t.commit();
logger.info("Beginning new transaction.");
t = s.beginTransaction();
logger.info("New transaction started successfully.");
}
i++;
}
logger.info("Read all results successfully.");
} catch (Exception e) {
logger.error("An exception was thrown");
throw e;
} finally {
logger.info("Closing session");
s.close();
}
}
public void testBuiltinPoolTransaction()
{
try {
doTestBuiltinCacheTransaction("builtin.cfg.xml", true);
} catch (Throwable e) {
logger.error("Builtin cache testing failed.", e);
throw new RuntimeException(e);
}
}
public void testC3P0PoolTransaction()
{
try {
doTestBuiltinCacheTransaction("with-c3p0.cfg.xml", true);
} catch (Throwable e) {
logger.error("C3P0 cache testing failed.", e);
throw new RuntimeException(e);
}
}
public void testProxoolPoolTransaction()
{
try {
doTestBuiltinCacheTransaction("with-proxool.cfg.xml", true);
} catch (Throwable e) {
logger.error("C3P0 cache testing failed.", e);
throw new RuntimeException(e);
}
}
}
The logging output (I cut the JUnit stack frames, to keep it shorter):Code:
2006-06-13 15:25:56,488 INFO [main] c3p0test.ATest (ATest.java:20) - Testing with pool settings from [builtin.cfg.xml].
2006-06-13 15:26:02,097 INFO [main] c3p0test.ATest (ATest.java:27) - Opening transaction
2006-06-13 15:26:02,100 INFO [main] c3p0test.ATest (ATest.java:29) - Running query
Hibernate: select a from a
2006-06-13 15:26:02,419 INFO [main] c3p0test.ATest (ATest.java:35) - Iterating...
2006-06-13 15:26:02,480 INFO [main] c3p0test.ATest (ATest.java:39) - Got [2]
2006-06-13 15:26:02,481 INFO [main] c3p0test.ATest (ATest.java:39) - Got [3]
2006-06-13 15:26:02,481 INFO [main] c3p0test.ATest (ATest.java:42) - Commiting transaction.
2006-06-13 15:26:02,488 INFO [main] c3p0test.ATest (ATest.java:44) - Beginning new transaction.
2006-06-13 15:26:02,489 INFO [main] c3p0test.ATest (ATest.java:46) - New transaction started successfully.
2006-06-13 15:26:02,490 INFO [main] c3p0test.ATest (ATest.java:39) - Got [4]
2006-06-13 15:26:02,491 INFO [main] c3p0test.ATest (ATest.java:50) - Read all results successfully.
2006-06-13 15:26:02,492 INFO [main] c3p0test.ATest (ATest.java:55) - Closing session
(See, the above just works, with hibernate's builtin pool)
Code:
2006-06-13 15:26:02,494 INFO [main] c3p0test.ATest (ATest.java:20) - Testing with pool settings from [with-c3p0.cfg.xml].
2006-06-13 15:26:05,562 INFO [main] c3p0test.ATest (ATest.java:27) - Opening transaction
2006-06-13 15:26:05,565 INFO [main] c3p0test.ATest (ATest.java:29) - Running query
Hibernate: select a from a
2006-06-13 15:26:05,589 INFO [main] c3p0test.ATest (ATest.java:35) - Iterating...
2006-06-13 15:26:05,590 INFO [main] c3p0test.ATest (ATest.java:39) - Got [2]
2006-06-13 15:26:05,593 INFO [main] c3p0test.ATest (ATest.java:39) - Got [3]
2006-06-13 15:26:05,594 INFO [main] c3p0test.ATest (ATest.java:42) - Commiting transaction.
2006-06-13 15:26:05,596 INFO [main] c3p0test.ATest (ATest.java:44) - Beginning new transaction.
2006-06-13 15:26:05,597 INFO [main] c3p0test.ATest (ATest.java:46) - New transaction started successfully.
2006-06-13 15:26:05,616 WARN [main] util.JDBCExceptionReporter (JDBCExceptionReporter.java:71) - SQL Error: 0, SQLState: null
2006-06-13 15:26:05,616 ERROR [main] util.JDBCExceptionReporter (JDBCExceptionReporter.java:72) - You can't operate on a closed ResultSet!!!
2006-06-13 15:26:05,617 ERROR [main] c3p0test.ATest (ATest.java:52) - An exception was thrown
2006-06-13 15:26:05,617 INFO [main] c3p0test.ATest (ATest.java:55) - Closing session
2006-06-13 15:26:05,623 ERROR [main] c3p0test.ATest (ATest.java:75) - C3P0 cache testing failed.
org.hibernate.exception.GenericJDBCException: could not advance using next()
at org.hibernate.exception.SQLStateConverter.handledNonSpecificException(SQLStateConverter.java:103)
at org.hibernate.exception.SQLStateConverter.convert(SQLStateConverter.java:91)
at org.hibernate.exception.JDBCExceptionHelper.convert(JDBCExceptionHelper.java:43)
at org.hibernate.exception.JDBCExceptionHelper.convert(JDBCExceptionHelper.java:29)
at org.hibernate.impl.ScrollableResultsImpl.next(ScrollableResultsImpl.java:104)
at uk.co.grs.c3p0test.ATest.doTestBuiltinCacheTransaction(ATest.java:37)
at uk.co.grs.c3p0test.ATest.testC3P0PoolTransaction(ATest.java:73)
Caused by: java.sql.SQLException: You can't operate on a closed ResultSet!!!
at com.mchange.v2.sql.SqlUtils.toSQLException(SqlUtils.java:106)
at com.mchange.v2.sql.SqlUtils.toSQLException(SqlUtils.java:65)
at com.mchange.v2.c3p0.impl.NewProxyResultSet.next(NewProxyResultSet.java:3047)
at org.hibernate.impl.ScrollableResultsImpl.next(ScrollableResultsImpl.java:99)
... 17 more
Caused by: java.lang.NullPointerException
at oracle.jdbc.driver.ScrollableResultSet.cacheRowAt(ScrollableResultSet.java:2086)
at oracle.jdbc.driver.ScrollableResultSet.isValidRow(ScrollableResultSet.java:2060)
at oracle.jdbc.driver.ScrollableResultSet.next(ScrollableResultSet.java:347)
at com.mchange.v2.c3p0.impl.NewProxyResultSet.next(NewProxyResultSet.java:3041)
... 18 more
Above, it fails with C3P0
Code:
2006-06-13 15:26:05,658 INFO [main] c3p0test.ATest (ATest.java:20) - Testing with pool settings from [with-proxool.cfg.xml].
2006-06-13 15:26:09,266 INFO [main] c3p0test.ATest (ATest.java:27) - Opening transaction
2006-06-13 15:26:09,267 INFO [main] c3p0test.ATest (ATest.java:29) - Running query
Hibernate: select a from a
2006-06-13 15:26:10,488 INFO [main] c3p0test.ATest (ATest.java:35) - Iterating...
2006-06-13 15:26:10,490 INFO [main] c3p0test.ATest (ATest.java:39) - Got [2]
2006-06-13 15:26:10,490 INFO [main] c3p0test.ATest (ATest.java:39) - Got [3]
2006-06-13 15:26:10,491 INFO [main] c3p0test.ATest (ATest.java:42) - Commiting transaction.
2006-06-13 15:26:10,494 INFO [main] c3p0test.ATest (ATest.java:44) - Beginning new transaction.
2006-06-13 15:26:10,495 INFO [main] c3p0test.ATest (ATest.java:46) - New transaction started successfully.
2006-06-13 15:26:10,496 ERROR [main] c3p0test.ATest (ATest.java:52) - An exception was thrown
2006-06-13 15:26:10,496 INFO [main] c3p0test.ATest (ATest.java:55) - Closing session
2006-06-13 15:26:10,527 WARN [main] proxool.ProxyConnection (ProxyConnection.java:180) - 000003 (01/01/00) - #1 registered a statement as closed which wasn't known to be open.
2006-06-13 15:26:10,529 ERROR [main] c3p0test.ATest (ATest.java:84) - C3P0 cache testing failed.
java.lang.NullPointerException
at oracle.jdbc.driver.ScrollableResultSet.cacheRowAt(ScrollableResultSet.java:2086)
at oracle.jdbc.driver.ScrollableResultSet.isValidRow(ScrollableResultSet.java:2060)
at oracle.jdbc.driver.ScrollableResultSet.next(ScrollableResultSet.java:347)
at org.hibernate.impl.ScrollableResultsImpl.next(ScrollableResultsImpl.java:99)
at uk.co.grs.c3p0test.ATest.doTestBuiltinCacheTransaction(ATest.java:37)
at uk.co.grs.c3p0test.ATest.testProxoolPoolTransaction(ATest.java:82)
And here it fails in a similar way, with Proxool
Name and version of the database you are using:RDBMS: Oracle, version: Oracle Database 10g Express Edition Release 10.2.0.1.0 - Production
JDBC driver: Oracle JDBC driver, version: 9.2.0.5.0
(It fails in a very similar way with RDBMS 9.2.0.5.0 as well.)
The generated SQL (show_sql=true):Just the literal SQL: "select a from a"
Debug level Hibernate log excerpt:The builtin pool case:
Code:
2006-06-13 15:33:20,101 INFO [main] c3p0test.ATest (ATest.java:39) - Got [3]
2006-06-13 15:33:20,102 INFO [main] c3p0test.ATest (ATest.java:42) - Commiting transaction.
2006-06-13 15:33:20,103 DEBUG [main] transaction.JDBCTransaction (JDBCTransaction.java:103) - commit
2006-06-13 15:33:20,103 DEBUG [main] impl.SessionImpl (SessionImpl.java:332) - automatically flushing session
2006-06-13 15:33:20,103 DEBUG [main] jdbc.JDBCContext (JDBCContext.java:185) - before transaction completion
2006-06-13 15:33:20,105 DEBUG [main] impl.SessionImpl (SessionImpl.java:388) - before transaction completion
2006-06-13 15:33:20,106 DEBUG [main] transaction.JDBCTransaction (JDBCTransaction.java:116) - committed JDBC Connection
2006-06-13 15:33:20,107 DEBUG [main] jdbc.JDBCContext (JDBCContext.java:199) - after transaction completion
2006-06-13 15:33:20,107 DEBUG [main] jdbc.ConnectionManager (ConnectionManager.java:398) - aggressively releasing JDBC connection
2006-06-13 15:33:20,382 DEBUG [main] jdbc.ConnectionManager (ConnectionManager.java:435) - releasing JDBC connection [ (open PreparedStatements: 1, globally: 1) (open ResultSets: 1, globally: 1)]
2006-06-13 15:33:20,384 DEBUG [main] connection.DriverManagerConnectionProvider (DriverManagerConnectionProvider.java:129) - returning connection to pool, pool size: 1
2006-06-13 15:33:20,384 DEBUG [main] impl.SessionImpl (SessionImpl.java:417) - after transaction completion
2006-06-13 15:33:20,387 INFO [main] c3p0test.ATest (ATest.java:44) - Beginning new transaction.
2006-06-13 15:33:20,387 DEBUG [main] transaction.JDBCTransaction (JDBCTransaction.java:54) - begin
2006-06-13 15:33:20,387 DEBUG [main] jdbc.ConnectionManager (ConnectionManager.java:415) - opening JDBC connection
2006-06-13 15:33:20,388 DEBUG [main] connection.DriverManagerConnectionProvider (DriverManagerConnectionProvider.java:93) - total checked-out connections: 0
2006-06-13 15:33:20,388 DEBUG [main] connection.DriverManagerConnectionProvider (DriverManagerConnectionProvider.java:99) - using pooled JDBC connection, pool size: 0
2006-06-13 15:33:20,389 DEBUG [main] transaction.JDBCTransaction (JDBCTransaction.java:59) - current autocommit status: false
2006-06-13 15:33:20,389 DEBUG [main] jdbc.JDBCContext (JDBCContext.java:194) - after transaction begin
2006-06-13 15:33:20,391 INFO [main] c3p0test.ATest (ATest.java:46) - New transaction started successfully.
2006-06-13 15:33:20,391 DEBUG [main] loader.Loader (Loader.java:1164) - result row:
2006-06-13 15:33:20,392 DEBUG [main] type.NullableType (NullableType.java:122) - returning '4' as column: a
2006-06-13 15:33:20,392 DEBUG [main] engine.StatefulPersistenceContext (StatefulPersistenceContext.java:748) - initializing non-lazy collections
2006-06-13 15:33:20,393 INFO [main] c3p0test.ATest (ATest.java:39) - Got [4]
The c3p0 case:
Code:
2006-06-13 15:33:21,640 INFO [main] c3p0test.ATest (ATest.java:39) - Got [3]
2006-06-13 15:33:21,640 INFO [main] c3p0test.ATest (ATest.java:42) - Commiting transaction.
2006-06-13 15:33:21,640 DEBUG [main] transaction.JDBCTransaction (JDBCTransaction.java:103) - commit
2006-06-13 15:33:21,641 DEBUG [main] impl.SessionImpl (SessionImpl.java:332) - automatically flushing session
2006-06-13 15:33:21,641 DEBUG [main] jdbc.JDBCContext (JDBCContext.java:185) - before transaction completion
2006-06-13 15:33:21,641 DEBUG [main] impl.SessionImpl (SessionImpl.java:388) - before transaction completion
2006-06-13 15:33:21,643 DEBUG [main] transaction.JDBCTransaction (JDBCTransaction.java:116) - committed JDBC Connection
2006-06-13 15:33:21,644 DEBUG [main] jdbc.JDBCContext (JDBCContext.java:199) - after transaction completion
2006-06-13 15:33:21,645 DEBUG [main] jdbc.ConnectionManager (ConnectionManager.java:398) - aggressively releasing JDBC connection
2006-06-13 15:33:21,645 DEBUG [main] jdbc.ConnectionManager (ConnectionManager.java:435) - releasing JDBC connection [ (open PreparedStatements: 1, globally: 1) (open ResultSets: 1, globally: 1)]
2006-06-13 15:33:21,649 DEBUG [main] impl.SessionImpl (SessionImpl.java:417) - after transaction completion
2006-06-13 15:33:21,650 INFO [main] c3p0test.ATest (ATest.java:44) - Beginning new transaction.
2006-06-13 15:33:21,650 DEBUG [main] transaction.JDBCTransaction (JDBCTransaction.java:54) - begin
2006-06-13 15:33:21,650 DEBUG [main] jdbc.ConnectionManager (ConnectionManager.java:415) - opening JDBC connection
2006-06-13 15:33:21,651 DEBUG [main] transaction.JDBCTransaction (JDBCTransaction.java:59) - current autocommit status: false
2006-06-13 15:33:21,652 DEBUG [main] jdbc.JDBCContext (JDBCContext.java:194) - after transaction begin
2006-06-13 15:33:21,653 INFO [main] c3p0test.ATest (ATest.java:46) - New transaction started successfully.
2006-06-13 15:33:21,659 DEBUG [main] util.JDBCExceptionReporter (JDBCExceptionReporter.java:63) - could not advance using next() [???]
java.sql.SQLException: You can't operate on a closed ResultSet!!!
at com.mchange.v2.sql.SqlUtils.toSQLException(SqlUtils.java:106)
at com.mchange.v2.sql.SqlUtils.toSQLException(SqlUtils.java:65)
at com.mchange.v2.c3p0.impl.NewProxyResultSet.next(NewProxyResultSet.java:3047)
at org.hibernate.impl.ScrollableResultsImpl.next(ScrollableResultsImpl.java:99)
at uk.co.grs.c3p0test.ATest.doTestBuiltinCacheTransaction(ATest.java:37)
at uk.co.grs.c3p0test.ATest.testC3P0PoolTransaction(ATest.java:73)
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:585)
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.RemoteTestRunner.runTests(RemoteTestRunner.java:478)
at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.run(RemoteTestRunner.java:344)
at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.main(RemoteTestRunner.java:196)
Caused by: java.lang.NullPointerException
at oracle.jdbc.driver.ScrollableResultSet.cacheRowAt(ScrollableResultSet.java:2086)
at oracle.jdbc.driver.ScrollableResultSet.isValidRow(ScrollableResultSet.java:2060)
at oracle.jdbc.driver.ScrollableResultSet.next(ScrollableResultSet.java:347)
at com.mchange.v2.c3p0.impl.NewProxyResultSet.next(NewProxyResultSet.java:3041)
... 18 more
regards,
Marcin[/code]