10:36 a.m.
[
http://opensource.atlassian.com/projects/hibernate/browse/HHH-2006?page=c...
]
Zhi An commented on HHH-2006:
-----------------------------
I believe I have found the open cursor leak.
In the method AbstractEntityPersister>>processGeneratedProperties, a
preparedStatement(PS) is created and its result set (RS) retrieved. Both are done through
the batcher.
However, in the batcher, the result set is added to resultSetsToClose but the
preparedStatement is not.
Contrast this with, say, the update method. In the update method, a test is run to see if
batch is ued. The prepared statement will be closed in the update method itself if batch
is not used.
I added the close and it fixed the problem. The following is the fixed method.
Please advice if I missed something in this.
private void processGeneratedProperties(
Serializable id,
Object entity,
Object[] state,
SessionImplementor session,
String selectionSQL,
boolean[] included ) {
session.getBatcher().executeBatch(); //force immediate execution of the insert
PreparedStatement ps = null;
try {
ps = session.getBatcher().prepareStatement( selectionSQL );
getIdentifierType().nullSafeSet( ps, id, 1, session );
ResultSet rs = session.getBatcher().getResultSet( ps );
if ( !rs.next() ) {
throw new HibernateException(
"Unable to locate row for retrieval of generated properties: " +
MessageHelper.infoString( this, id, getFactory() )
);
}
for ( int i = 0; i < getPropertySpan(); i++ ) {
if ( included[i] ) {
state[i] = getPropertyTypes()[i].hydrate( rs, getPropertyAliases( "", i ),
session, entity );
setPropertyValue( entity, i, state[i], session.getEntityMode() );
}
}
} catch( SQLException sqle ) {
JDBCExceptionHelper.convert(
getFactory().getSQLExceptionConverter(),
sqle,
"unable to select generated column values",
selectionSQL
);
}
//Added code
finally {
try {
session.getBatcher().closeStatement( ps );
} catch (SQLException e) {
throw new HibernateException(
"Error while try to close the statement: " +
MessageHelper.infoString( this, id, getFactory() )
);
}
//End of added code.
}
ORA-01000: maximum open cursors exceeded
----------------------------------------
Key: HHH-2006
URL: http://opensource.atlassian.com/projects/hibernate/browse/HHH-2006
Project: Hibernate3
Type: Bug
Components: core
Versions: 3.1.3
Environment: Does not seem to matter. Using Oracle 10g JDBC, Oracle 9i database,
Hibernate 3.1.3, and the LocalSessionFactoryBean. But reproduced with 9i driver.
Reporter: Zhi An
Update objects seemed to leave cursors open.
If a loop, I am looping through all the rows in a table and update each row.
If the table is large enough, I will run out of Oracle cursors. I am open and close a
R/W transaction for each row.
If I only read the object, I will not run out the cursors.
The jUnit test is as follows. Please fill in a correct table name/dao class.
There was some mentioning on JBOSS that Oracle JDBC might be slow closing cursors. But
the cursors run out even if I add delays to each row update.
Thanks for your help.
public void testVolume() throws Exception {
<DAOclass> dao =
(DAOclass) getAppContext().getBean(<BeanName>));
List<Long> ids = dao.getAllIds();
for (Long id : ids) {
this.update(id);
}
//If we reach here, success. The error was that cursor will be exhausted.
}
private void update(final Long id) throws Exception {
Runnable r = new Runnable() {
public void run() {
<DAOclass> dao =
(DAOclass) getAppContext().getBean(<BeanName>));
ObjectClass log = dao.getById(id);
String ext = log.getSomething();
if (ext != null && ext.startsWith("-")) {
log.setSomething(ext.substring(1));
} else {
log.setExtTransactionId("-" + ext);
}
}
};
this.runInTransaction(r);
}
Error log:
Hibernate:
/* load com.widerthan.rbt.model.data.ProfileTransactionLog */ select
profiletra0_.LOG_TRANSACTION_ID as LOG1_21_0_,
profiletra0_.VERSION as VERSION21_0_,
profiletra0_.CUSTOMER_NAME as CUSTOMER3_21_0_,
profiletra0_.REQUEST_TRANSACTION_ID as REQUEST4_21_0_,
profiletra0_.REQUEST_OPERATOR_ID as REQUEST5_21_0_,
profiletra0_.TRANSACTION_TYPE_ID as TRANSACT6_21_0_,
profiletra0_.SERVICE_CHANNEL_ID as SERVICE7_21_0_,
profiletra0_.USER_MSISDN as USER8_21_0_,
profiletra0_.DESCRIPTION as DESCRIPT9_21_0_,
profiletra0_.BILLING_TRANSACTION_ID as BILLING10_21_0_,
profiletra0_.PRICE as PRICE21_0_,
profiletra0_.EXT_TRANSACTION_ID as EXT12_21_0_,
profiletra0_.SERVICE_NAME as SERVICE13_21_0_,
profiletra0_.STATUS as STATUS21_0_,
profiletra0_.PROCESSING_TIME as PROCESSING15_21_0_,
profiletra0_.EXT_PROCESSING_TIME as EXT16_21_0_,
profiletra0_.LOGGED as LOGGED21_0_,
profiletra0_.USER_ID as USER18_21_0_,
profiletra0_.CUSTOMER_ID as CUSTOMER19_21_0_,
profiletra0_.rowid as rowid_0_
from
MVNO.LOG_TRANSACTION_PROFILE profiletra0_
where
profiletra0_.LOG_TRANSACTION_ID=?
13:37:51,434 WARN [JDBCExceptionReporter] SQL Error: 1000, SQLState: 72000
13:37:51,434 ERROR [JDBCExceptionReporter] ORA-01000: maximum open cursors exceeded
13:37:51,434 INFO [DefaultLoadEventListener] Error performing load command
org.hibernate.exception.GenericJDBCException: could not load an entity:
[com.widerthan.rbt.model.data.ProfileTransactionLog#13544]
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.loader.Loader.loadEntity(Loader.java:1799)
at org.hibernate.loader.entity.AbstractEntityLoader.load(AbstractEntityLoader.java:47)
at org.hibernate.loader.entity.AbstractEntityLoader.load(AbstractEntityLoader.java:41)
at
org.hibernate.persister.entity.AbstractEntityPersister.load(AbstractEntityPersister.java:2730)
at
org.hibernate.event.def.DefaultLoadEventListener.loadFromDatasource(DefaultLoadEventListener.java:365)
at
org.hibernate.event.def.DefaultLoadEventListener.doLoad(DefaultLoadEventListener.java:346)
at
org.hibernate.event.def.DefaultLoadEventListener.load(DefaultLoadEventListener.java:123)
at
org.hibernate.event.def.DefaultLoadEventListener.proxyOrLoad(DefaultLoadEventListener.java:177)
at
org.hibernate.event.def.DefaultLoadEventListener.onLoad(DefaultLoadEventListener.java:87)
at org.hibernate.impl.SessionImpl.fireLoad(SessionImpl.java:862)
at org.hibernate.impl.SessionImpl.get(SessionImpl.java:799)
at org.hibernate.impl.SessionImpl.get(SessionImpl.java:792)
at
org.springframework.orm.hibernate3.HibernateTemplate$1.doInHibernate(HibernateTemplate.java:452)
at
org.springframework.orm.hibernate3.HibernateTemplate.execute(HibernateTemplate.java:366)
at org.springframework.orm.hibernate3.HibernateTemplate.get(HibernateTemplate.java:446)
at org.springframework.orm.hibernate3.HibernateTemplate.get(HibernateTemplate.java:440)
at com.widerthan.rbt.dao.hibernate.BaseHibernateDAO.getById(BaseHibernateDAO.java:152)
at com.widerthan.rbt.dao.hibernate.BaseHibernateDAO.getById(BaseHibernateDAO.java:129)
at
com.widerthan.rbt.dao.hibernate.ProfileTransactionLogDAOTest$1.run(ProfileTransactionLogDAOTest.java:33)
at com.widerthan.rbt.TestEventImpl.runInTransaction(TestEventImpl.java:21)
at sun.reflect.GeneratedMethodAccessor12.invoke(Unknown Source)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:585)
at
org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:287)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:181)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:148)
at
org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:96)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:170)
at
org.springframework.orm.hibernate3.HibernateInterceptor.invoke(HibernateInterceptor.java:88)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:170)
at
org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:176)
at $Proxy1.runInTransaction(Unknown Source)
at com.widerthan.rbt.BaseTestCase.runInTransaction(BaseTestCase.java:175)
at
com.widerthan.rbt.dao.hibernate.ProfileTransactionLogDAOTest.update(ProfileTransactionLogDAOTest.java:47)
at
com.widerthan.rbt.dao.hibernate.ProfileTransactionLogDAOTest.testVolume(ProfileTransactionLogDAOTest.java:23)
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:164)
at junit.framework.TestCase.runBare(TestCase.java:130)
at junit.framework.TestResult$1.protect(TestResult.java:110)
at junit.framework.TestResult.runProtected(TestResult.java:128)
at junit.framework.TestResult.run(TestResult.java:113)
at junit.framework.TestCase.run(TestCase.java:120)
at junit.framework.TestSuite.runTest(TestSuite.java:228)
at junit.framework.TestSuite.run(TestSuite.java:223)
at junit.textui.TestRunner.doRun(TestRunner.java:115)
at com.intellij.rt.execution.junit2.IdeaJUnitAgent.doRun(IdeaJUnitAgent.java:58)
at junit.textui.TestRunner.start(TestRunner.java:179)
at
com.intellij.rt.execution.junit.TextTestRunner2.startRunnerWithArgs(TextTestRunner2.java:23)
at
com.intellij.rt.execution.junit2.JUnitStarter.prepareStreamsAndStart(JUnitStarter.java:98)
at com.intellij.rt.execution.junit2.JUnitStarter.main(JUnitStarter.java:32)
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 com.intellij.rt.execution.application.AppMain.main(AppMain.java:90)
Caused by: java.sql.SQLException: ORA-01000: maximum open cursors exceeded
at oracle.jdbc.driver.DatabaseError.throwSqlException(DatabaseError.java:112)
at oracle.jdbc.driver.T4CTTIoer.processError(T4CTTIoer.java:331)
at oracle.jdbc.driver.T4CTTIoer.processError(T4CTTIoer.java:288)
at oracle.jdbc.driver.T4C8Oall.receive(T4C8Oall.java:743)
at oracle.jdbc.driver.T4CPreparedStatement.doOall8(T4CPreparedStatement.java:216)
at
oracle.jdbc.driver.T4CPreparedStatement.executeForDescribe(T4CPreparedStatement.java:799)
at oracle.jdbc.driver.OracleStatement.executeMaybeDescribe(OracleStatement.java:1039)
at
oracle.jdbc.driver.T4CPreparedStatement.executeMaybeDescribe(T4CPreparedStatement.java:839)
at oracle.jdbc.driver.OracleStatement.doExecuteWithTimeout(OracleStatement.java:1132)
at
oracle.jdbc.driver.OraclePreparedStatement.executeInternal(OraclePreparedStatement.java:3285)
at
oracle.jdbc.driver.OraclePreparedStatement.executeQuery(OraclePreparedStatement.java:3329)
at org.hibernate.jdbc.AbstractBatcher.getResultSet(AbstractBatcher.java:139)
at org.hibernate.loader.Loader.getResultSet(Loader.java:1669)
at org.hibernate.loader.Loader.doQuery(Loader.java:662)
at org.hibernate.loader.Loader.doQueryAndInitializeNonLazyCollections(Loader.java:224)
at org.hibernate.loader.Loader.loadEntity(Loader.java:1785)
... 57 more
13:37:51,574 INFO [DriverManagerConnectionProvider] cleaning up connection pool:
jdbc:oracle:thin:@10.10.50.234:1521:CRBDEV1
org.springframework.jdbc.UncategorizedSQLException: Hibernate operation: could not load
an entity: [com.widerthan.rbt.model.data.ProfileTransactionLog#13544]; uncategorized
SQLException for SQL [/* load com.widerthan.rbt.model.data.ProfileTransactionLog */ select
profiletra0_.LOG_TRANSACTION_ID as LOG1_21_0_, profiletra0_.VERSION as VERSION21_0_,
profiletra0_.CUSTOMER_NAME as CUSTOMER3_21_0_, profiletra0_.REQUEST_TRANSACTION_ID as
REQUEST4_21_0_, profiletra0_.REQUEST_OPERATOR_ID as REQUEST5_21_0_,
profiletra0_.TRANSACTION_TYPE_ID as TRANSACT6_21_0_, profiletra0_.SERVICE_CHANNEL_ID as
SERVICE7_21_0_, profiletra0_.USER_MSISDN as USER8_21_0_, profiletra0_.DESCRIPTION as
DESCRIPT9_21_0_, profiletra0_.BILLING_TRANSACTION_ID as BILLING10_21_0_,
profiletra0_.PRICE as PRICE21_0_, profiletra0_.EXT_TRANSACTION_ID as EXT12_21_0_,
profiletra0_.SERVICE_NAME as SERVICE13_21_0_, profiletra0_.STATUS as STATUS21_0_,
profiletra0_.PROCESSING_TIME as PROCESSING15_21_0_, profiletra0_.EXT_PROCESSING_TIME as
EXT16_21_0_, profiletra0_.LOGGED as LOGGED21_0_, profiletra0_.USER_ID as USER18_21_0_,
profiletra0_.CUSTOMER_ID as CUSTOMER19_21_0_, profiletra0_.rowid as rowid_0_ from
MVNO.LOG_TRANSACTION_PROFILE profiletra0_ where profiletra0_.LOG_TRANSACTION_ID=?]; SQL
state [72000]; error code [1000]; ORA-01000: maximum open cursors exceeded
; nested exception is java.sql.SQLException: ORA-01000: maximum open cursors exceeded
java.sql.SQLException: ORA-01000: maximum open cursors exceeded
at oracle.jdbc.driver.DatabaseError.throwSqlException(DatabaseError.java:112)
at oracle.jdbc.driver.T4CTTIoer.processError(T4CTTIoer.java:331)
at oracle.jdbc.driver.T4CTTIoer.processError(T4CTTIoer.java:288)
at oracle.jdbc.driver.T4C8Oall.receive(T4C8Oall.java:743)
at oracle.jdbc.driver.T4CPreparedStatement.doOall8(T4CPreparedStatement.java:216)
at
oracle.jdbc.driver.T4CPreparedStatement.executeForDescribe(T4CPreparedStatement.java:799)
at oracle.jdbc.driver.OracleStatement.executeMaybeDescribe(OracleStatement.java:1039)
at
oracle.jdbc.driver.T4CPreparedStatement.executeMaybeDescribe(T4CPreparedStatement.java:839)
at oracle.jdbc.driver.OracleStatement.doExecuteWithTimeout(OracleStatement.java:1132)
at
oracle.jdbc.driver.OraclePreparedStatement.executeInternal(OraclePreparedStatement.java:3285)
at
oracle.jdbc.driver.OraclePreparedStatement.executeQuery(OraclePreparedStatement.java:3329)
at org.hibernate.jdbc.AbstractBatcher.getResultSet(AbstractBatcher.java:139)
at org.hibernate.loader.Loader.getResultSet(Loader.java:1669)
at org.hibernate.loader.Loader.doQuery(Loader.java:662)
at org.hibernate.loader.Loader.doQueryAndInitializeNonLazyCollections(Loader.java:224)
at org.hibernate.loader.Loader.loadEntity(Loader.java:1785)
at org.hibernate.loader.entity.AbstractEntityLoader.load(AbstractEntityLoader.java:47)
at org.hibernate.loader.entity.AbstractEntityLoader.load(AbstractEntityLoader.java:41)
at
org.hibernate.persister.entity.AbstractEntityPersister.load(AbstractEntityPersister.java:2730)
at
org.hibernate.event.def.DefaultLoadEventListener.loadFromDatasource(DefaultLoadEventListener.java:365)
at
org.hibernate.event.def.DefaultLoadEventListener.doLoad(DefaultLoadEventListener.java:346)
at
org.hibernate.event.def.DefaultLoadEventListener.load(DefaultLoadEventListener.java:123)
at
org.hibernate.event.def.DefaultLoadEventListener.proxyOrLoad(DefaultLoadEventListener.java:177)
at
org.hibernate.event.def.DefaultLoadEventListener.onLoad(DefaultLoadEventListener.java:87)
at org.hibernate.impl.SessionImpl.fireLoad(SessionImpl.java:862)
at org.hibernate.impl.SessionImpl.get(SessionImpl.java:799)
at org.hibernate.impl.SessionImpl.get(SessionImpl.java:792)
at
org.springframework.orm.hibernate3.HibernateTemplate$1.doInHibernate(HibernateTemplate.java:452)
at
org.springframework.orm.hibernate3.HibernateTemplate.execute(HibernateTemplate.java:366)
at org.springframework.orm.hibernate3.HibernateTemplate.get(HibernateTemplate.java:446)
at org.springframework.orm.hibernate3.HibernateTemplate.get(HibernateTemplate.java:440)
at com.widerthan.rbt.dao.hibernate.BaseHibernateDAO.getById(BaseHibernateDAO.java:152)
at com.widerthan.rbt.dao.hibernate.BaseHibernateDAO.getById(BaseHibernateDAO.java:129)
at
com.widerthan.rbt.dao.hibernate.ProfileTransactionLogDAOTest$1.run(ProfileTransactionLogDAOTest.java:33)
at com.widerthan.rbt.TestEventImpl.runInTransaction(TestEventImpl.java:21)
at sun.reflect.GeneratedMethodAccessor12.invoke(Unknown Source)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at
org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:287)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:181)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:148)
at
org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:96)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:170)
at
org.springframework.orm.hibernate3.HibernateInterceptor.invoke(HibernateInterceptor.java:88)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:170)
at
org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:176)
at $Proxy1.runInTransaction(Unknown Source)
at com.widerthan.rbt.BaseTestCase.runInTransaction(BaseTestCase.java:175)
at
com.widerthan.rbt.dao.hibernate.ProfileTransactionLogDAOTest.update(ProfileTransactionLogDAOTest.java:47)
at
com.widerthan.rbt.dao.hibernate.ProfileTransactionLogDAOTest.testVolume(ProfileTransactionLogDAOTest.java:23)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at com.intellij.rt.execution.junit2.JUnitStarter.main(JUnitStarter.java:32)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at com.intellij.rt.execution.application.AppMain.main(AppMain.java:90)
--
This message is automatically generated by JIRA.
-
If you think it was sent incorrectly contact one of the administrators:
http://opensource.atlassian.com/projects/hibernate/secure/Administrators....
-
For more information on JIRA, see:
http://www.atlassian.com/software/jira