Issue Type: Bug Bug
Affects Versions: 4.1.9
Assignee: Unassigned
Attachments: BOTEMPLATE.PKG_BOT_TESTS.pck, BOT_TEST_NUMVALUE.sql, CursorFromCallableTest.java, CursorFromCallableTest.log, NumValue.java, persistence.xml
Components: entity-manager
Created: 11/Feb/13 9:02 AM
Description:

After migrating from Hibernate 3.6 to 4.1.9, the following use case fails with ORA-01000: maximum open cursors exceeded.

We have a PL/SQL package PKG_BOT_TESTS with a simple function f_test_ReturnNonEmptyCursor returning a cursor with 2 lines where the columns can be mapped to the table BOT_TEST_NUMVALUE:

BOTEMPLATE.PKG_BOT_TESTS.pck
CREATE OR REPLACE PACKAGE PKG_BOT_TESTS IS
  
  FUNCTION f_test_ReturnNonEmptyCursor RETURN SYS_REFCURSOR;

END PKG_BOT_TESTS;
/
CREATE OR REPLACE PACKAGE BODY PKG_BOT_TESTS IS

  FUNCTION f_test_ReturnNonEmptyCursor RETURN SYS_REFCURSOR IS
    l_Cursor SYS_REFCURSOR;
  BEGIN
    OPEN l_Cursor FOR
      SELECT 1 AS BOT_NUM,
             'Line 1' AS BOT_VALUE
      FROM   DUAL
      UNION
      SELECT 2 AS BOT_NUM,
             'Line 2' AS BOT_VALUE
      FROM   DUAL;
    RETURN(l_Cursor);
  END f_test_ReturnNonEmptyCursor;

END PKG_BOT_TESTS;
/
BOT_TEST_NUMVALUE.sql
create table BOT_TEST_NUMVALUE
(
  bot_num   NUMBER(16) not null,
  bot_value VARCHAR2(255)
)
 
alter table BOT_TEST_NUMVALUE
  add constraint PK_NUM primary key (BOT_NUM);

The data class that maps this table looks like this:

NumValue.java (excerpt)
@Entity
@Table(name="BOT_NUMVALUE")
@NamedNativeQueries({
    @NamedNativeQuery(name="NumValue.getSomeValues",
            query = "{ ? = call BOTEMPLATE.PKG_BOT_TESTS.f_test_ReturnNonEmptyCursor() }",
            resultClass=NumValue.class, hints={@QueryHint(name="org.hibernate.callable", value="true")})
})
public class NumValue {
    @Id
    @Column(name="BOT_NUM", nullable=false)
    private long num;
    @Column(name="BOT_VALUE")
    private String value;

    public long getNum() {
        return num;
    }

    public void setNum(long num) {
        this.num = num;
    }

    public String getValue() {
        return value;
    }

    public void setValue(String value) {
        this.value = value;
    }
}

As mentioned, the following test works fine with Hibernate 3.6 but fails with Hibernate 4.1.9 (ORA-01000: maximum open cursors exceeded):

CursorFromCallableTest.java
public class CursorFromCallableTest {

    @Test
    public void testGetObjectListFromCallableCursor_X500() throws Exception {
        Properties emfProps = new Properties();
        emfProps.setProperty("hibernate.connection.url", "...");
        emfProps.setProperty("hibernate.connection.username", "...");
        emfProps.setProperty("hibernate.connection.password", "...");

        EntityManagerFactory emf = Persistence.createEntityManagerFactory("CursorFromCallableTest", emfProps);
        EntityManager context = null;
        try {
            context = emf.createEntityManager();

            for (int i = 0; i < 500; i++) {
                Assert.assertEquals(2, getObjectListFromCalleableCursor(context).size());
            }

        } finally {
            if (context != null) {
                context.close();
            }
            emf.close();
        }
    }

    private List<NumValue> getObjectListFromCalleableCursor(EntityManager context) {
        TypedQuery<NumValue> query = context.createNamedQuery("NumValue.getSomeValues", NumValue.class);
        return query.getResultList();
    }
}

This is the JUnit stack trace:

javax.persistence.QueryTimeoutException: could not execute query
	at org.hibernate.ejb.AbstractEntityManagerImpl.convert(AbstractEntityManagerImpl.java:1339)
	at org.hibernate.ejb.AbstractEntityManagerImpl.convert(AbstractEntityManagerImpl.java:1300)
	at org.hibernate.ejb.QueryImpl.getResultList(QueryImpl.java:273)
	at CursorFromCallableTest.getObjectListFromCalleableCursor(CursorFromCallableTest.java:40)
	at CursorFromCallableTest.testGetObjectListFromCalleableCursor_X500(CursorFromCallableTest.java:27)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(Unknown Source)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
	at java.lang.reflect.Method.invoke(Unknown Source)
	at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:44)
	at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:15)
	at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:41)
	at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:20)
	at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:76)
	at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:50)
	at org.junit.runners.ParentRunner$3.run(ParentRunner.java:193)
	at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:52)
	at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:191)
	at org.junit.runners.ParentRunner.access$000(ParentRunner.java:42)
	at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:184)
	at org.junit.runners.ParentRunner.run(ParentRunner.java:236)
	at org.eclipse.jdt.internal.junit4.runner.JUnit4TestReference.run(JUnit4TestReference.java:49)
	at org.eclipse.jdt.internal.junit.runner.TestExecution.run(TestExecution.java:38)
	at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.runTests(RemoteTestRunner.java:467)
	at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.runTests(RemoteTestRunner.java:683)
	at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.run(RemoteTestRunner.java:390)
	at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.main(RemoteTestRunner.java:197)
Caused by: org.hibernate.QueryTimeoutException: could not execute query
	at org.hibernate.exception.internal.SQLStateConversionDelegate.convert(SQLStateConversionDelegate.java:151)
	at org.hibernate.exception.internal.StandardSQLExceptionConverter.convert(StandardSQLExceptionConverter.java:49)
	at org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:125)
	at org.hibernate.loader.Loader.doList(Loader.java:2519)
	at org.hibernate.loader.Loader.doList(Loader.java:2502)
	at org.hibernate.loader.Loader.listIgnoreQueryCache(Loader.java:2332)
	at org.hibernate.loader.Loader.list(Loader.java:2327)
	at org.hibernate.loader.custom.CustomLoader.list(CustomLoader.java:338)
	at org.hibernate.internal.SessionImpl.listCustomQuery(SessionImpl.java:1783)
	at org.hibernate.internal.AbstractSessionImpl.list(AbstractSessionImpl.java:231)
	at org.hibernate.internal.SQLQueryImpl.list(SQLQueryImpl.java:157)
	at org.hibernate.ejb.QueryImpl.getResultList(QueryImpl.java:264)
	... 24 more
Caused by: java.sql.SQLException: ORA-01000: maximum open cursors exceeded
ORA-06512: at "BOTEMPLATE.PKG_BOT_TESTS", line 37
ORA-06512: at line 1

	at oracle.jdbc.driver.T4CTTIoer.processError(T4CTTIoer.java:445)
	at oracle.jdbc.driver.T4CTTIoer.processError(T4CTTIoer.java:396)
	at oracle.jdbc.driver.T4C8Oall.processError(T4C8Oall.java:879)
	at oracle.jdbc.driver.T4CTTIfun.receive(T4CTTIfun.java:450)
	at oracle.jdbc.driver.T4CTTIfun.doRPC(T4CTTIfun.java:192)
	at oracle.jdbc.driver.T4C8Oall.doOALL(T4C8Oall.java:531)
	at oracle.jdbc.driver.T4CCallableStatement.doOall8(T4CCallableStatement.java:204)
	at oracle.jdbc.driver.T4CCallableStatement.executeForRows(T4CCallableStatement.java:1041)
	at oracle.jdbc.driver.OracleStatement.doExecuteWithTimeout(OracleStatement.java:1329)
	at oracle.jdbc.driver.OraclePreparedStatement.executeInternal(OraclePreparedStatement.java:3584)
	at oracle.jdbc.driver.OraclePreparedStatement.execute(OraclePreparedStatement.java:3685)
	at oracle.jdbc.driver.OracleCallableStatement.execute(OracleCallableStatement.java:4714)
	at oracle.jdbc.driver.OraclePreparedStatementWrapper.execute(OraclePreparedStatementWrapper.java:1376)
	at com.mchange.v2.c3p0.impl.NewProxyCallableStatement.execute(NewProxyCallableStatement.java:3044)
	at org.hibernate.dialect.Oracle8iDialect.getResultSet(Oracle8iDialect.java:516)
	at org.hibernate.engine.jdbc.internal.proxy.CallableStatementProxyHandler.executeQuery(CallableStatementProxyHandler.java:56)
	at org.hibernate.engine.jdbc.internal.proxy.CallableStatementProxyHandler.continueInvocation(CallableStatementProxyHandler.java:52)
	at org.hibernate.engine.jdbc.internal.proxy.AbstractProxyHandler.invoke(AbstractProxyHandler.java:81)
	at $Proxy13.executeQuery(Unknown Source)
	at org.hibernate.loader.Loader.getResultSet(Loader.java:2031)
	at org.hibernate.loader.Loader.executeQueryStatement(Loader.java:1832)
	at org.hibernate.loader.Loader.executeQueryStatement(Loader.java:1811)
	at org.hibernate.loader.Loader.doQuery(Loader.java:899)
	at org.hibernate.loader.Loader.doQueryAndInitializeNonLazyCollections(Loader.java:341)
	at org.hibernate.loader.Loader.doList(Loader.java:2516)
	... 32 more

The test may depend on your Oracle configuration of the maximum number of cursors. The number of iterations should be greater than the configured limit.

Please also note the attached CursorFromCalleable.log file. The information from c3p0 about the multiple prepared statement indicates Hibernate has not closed the prepared statement from the previous call as noted in https://forum.hibernate.org/viewtopic.php?f=1&t=942656.

I may supply additional information if needed. Thank you!

Environment: Hibernate 4.1.9 Final
Oracle JDBC Thin Driver 11.2.0.3
Project: Hibernate ORM
Labels: query
Priority: Critical Critical
Reporter: Pierre Post
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators
For more information on JIRA, see: http://www.atlassian.com/software/jira