Wrapped Hibernate SQLGrammarException loses the potential SQL statement that caused the exception [SPR-6304]

[spring-projects-issues]

Sébastien Launay opened SPR-6304 and commented

When an org.hibernate.exception.SQLGrammarException occurs because a table is missing i have the following stace trace:

Caused by: org.springframework.beans.BeanInstantiationException: Could not instantiate bean class [org.jasig.cas.services.DefaultServicesManagerImpl]:
Constructor threw exception; nested exception is org.springframework.dao.InvalidDataAccessResourceUsageException: could not execute query;
nested exception is org.hibernate.exception.SQLGrammarException: could not execute query
 at org.springframework.beans.BeanUtils.instantiateClass(BeanUtils.java:115)
 at org.springframework.beans.factory.support.SimpleInstantiationStrategy.instantiate(SimpleInstantiationStrategy.java:87)
 at org.springframework.beans.factory.support.ConstructorResolver.autowireConstructor(ConstructorResolver.java:248)
 ... 76 more
Caused by: org.springframework.dao.InvalidDataAccessResourceUsageException: could not execute query;
nested exception is org.hibernate.exception.SQLGrammarException: could not execute query
 at org.springframework.orm.hibernate3.SessionFactoryUtils.convertHibernateAccessException(SessionFactoryUtils.java:630)
 at org.springframework.orm.jpa.vendor.HibernateJpaDialect.translateExceptionIfPossible(HibernateJpaDialect.java:95)
 at org.springframework.dao.support.DataAccessUtils.translateIfNecessary(DataAccessUtils.java:212)
 at org.springframework.orm.jpa.JpaAccessor.translateIfNecessary(JpaAccessor.java:152)
 at org.springframework.orm.jpa.JpaTemplate.execute(JpaTemplate.java:189)
 at org.springframework.orm.jpa.JpaTemplate.executeFind(JpaTemplate.java:151)
 at org.springframework.orm.jpa.JpaTemplate.find(JpaTemplate.java:311)
 at org.springframework.orm.jpa.JpaTemplate.find(JpaTemplate.java:307)
 at org.jasig.cas.services.JpaServiceRegistryDaoImpl.load(JpaServiceRegistryDaoImpl.java:30)
 at org.jasig.cas.services.DefaultServicesManagerImpl.load(DefaultServicesManagerImpl.java:134)
 at org.jasig.cas.services.DefaultServicesManagerImpl.<init>(DefaultServicesManagerImpl.java:61)
 at org.jasig.cas.services.DefaultServicesManagerImpl.<init>(DefaultServicesManagerImpl.java:43)
 at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
 at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:39)
 at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:27)
 at java.lang.reflect.Constructor.newInstance(Constructor.java:513)
 at org.springframework.beans.BeanUtils.instantiateClass(BeanUtils.java:100)
 ... 78 more
Caused by: org.hibernate.exception.SQLGrammarException: could not execute query
 at org.hibernate.exception.SQLStateConverter.convert(SQLStateConverter.java:90)
 at org.hibernate.exception.JDBCExceptionHelper.convert(JDBCExceptionHelper.java:66)
 at org.hibernate.loader.Loader.doList(Loader.java:2235)
 at org.hibernate.loader.Loader.listIgnoreQueryCache(Loader.java:2129)
 at org.hibernate.loader.Loader.list(Loader.java:2124)
 at org.hibernate.loader.hql.QueryLoader.list(QueryLoader.java:401)
 at org.hibernate.hql.ast.QueryTranslatorImpl.list(QueryTranslatorImpl.java:363)
 at org.hibernate.engine.query.HQLQueryPlan.performList(HQLQueryPlan.java:196)
 at org.hibernate.impl.SessionImpl.list(SessionImpl.java:1149)
 at org.hibernate.impl.QueryImpl.list(QueryImpl.java:102)
 at org.hibernate.ejb.QueryImpl.getResultList(QueryImpl.java:67)
 at org.springframework.orm.jpa.JpaTemplate$9.doInJpa(JpaTemplate.java:319)
 at org.springframework.orm.jpa.JpaTemplate.execute(JpaTemplate.java:184)
 ... 90 more
Caused by: java.sql.SQLException: ORA-00942: table or view does not exist
 at oracle.jdbc.driver.SQLStateMapping.newSQLException(SQLStateMapping.java:133)
 at oracle.jdbc.driver.DatabaseError.newSQLException(DatabaseError.java:115)
 at oracle.jdbc.driver.DatabaseError.throwSqlException(DatabaseError.java:221)
 at oracle.jdbc.driver.T4CTTIoer.processError(T4CTTIoer.java:467)
 at oracle.jdbc.driver.T4CTTIoer.processError(T4CTTIoer.java:417)
 at oracle.jdbc.driver.T4C8Oall.receive(T4C8Oall.java:1084)
 at oracle.jdbc.driver.T4CPreparedStatement.doOall8(T4CPreparedStatement.java:215)
 at oracle.jdbc.driver.T4CPreparedStatement.executeForDescribe(T4CPreparedStatement.java:1032)
 at oracle.jdbc.driver.T4CPreparedStatement.executeMaybeDescribe(T4CPreparedStatement.java:1139)
 at oracle.jdbc.driver.OracleStatement.doExecuteWithTimeout(OracleStatement.java:1471)
 at oracle.jdbc.driver.OraclePreparedStatement.executeInternal(OraclePreparedStatement.java:3874)
 at oracle.jdbc.driver.OraclePreparedStatement.executeQuery(OraclePreparedStatement.java:3944)
 at oracle.jdbc.driver.OraclePreparedStatementWrapper.executeQuery(OraclePreparedStatementWrapper.java:3613)
 at org.apache.commons.dbcp.DelegatingPreparedStatement.executeQuery(DelegatingPreparedStatement.java:93)
 at org.hibernate.jdbc.AbstractBatcher.getResultSet(AbstractBatcher.java:208)
 at org.hibernate.loader.Loader.getResultSet(Loader.java:1812)
 at org.hibernate.loader.Loader.doQuery(Loader.java:697)
 at org.hibernate.loader.Loader.doQueryAndInitializeNonLazyCollections(Loader.java:259)
 at org.hibernate.loader.Loader.doList(Loader.java:2232)
 ... 100 more

Because the SQLGrammarException is wrapped like any other exception we lose the SQL statement that caused the exception which can be handy in my case because I do not know which table does not exist :(.

This maybe more of a Hibernate issue than a Spring issue (SQL in not append in the message but kept in a private field) but this is not the case for the parent class (org.hibernate.JDBCException) where the SQL statement is integrated by Spring in the stack trace.

By looking at the 3.x source code, I think this issue also occurs in the future 3.0 version but I have not tested it.

---

Affects: 2.5.6

Attachments:

• SPR-6304-2.5.x-hibernate-sql-grammar-exception-2009-11-05.patch (914 bytes)

Referenced from: commits 86934e2

[spring-projects-issues]

Sébastien Launay commented

A patch against 2.5.x trunk fixing this issue by using Spring HibernateJdbcException (used for JDBCException).

By applying this patch the following stack trace will be used instead for my previous missing table:

Caused by: org.springframework.beans.BeanInstantiationException: Could not instantiate bean class [org.jasig.cas.services.DefaultServicesManagerImpl]:
Constructor threw exception; nested exception is org.springframework.dao.InvalidDataAccessResourceUsageException: could not execute query;
nested exception is org.springframework.orm.hibernate3.HibernateJdbcException: JDBC exception on Hibernate data access:
SQLException for SQL [select [...] from CAS_REGISTEREDSERVICE registered0_];
SQL state [42000]; error code [942]; could not execute query; nested exception is org.hibernate.exception.SQLGrammarException: could not execute query
 	at org.springframework.beans.BeanUtils.instantiateClass(BeanUtils.java:115)
 	at org.springframework.beans.factory.support.SimpleInstantiationStrategy.instantiate(SimpleInstantiationStrategy.java:87)
 	at org.springframework.beans.factory.support.ConstructorResolver.autowireConstructor(ConstructorResolver.java:248)
 	... 76 more
Caused by: org.springframework.dao.InvalidDataAccessResourceUsageException: could not execute query;
nested exception is org.springframework.orm.hibernate3.HibernateJdbcException: JDBC exception on Hibernate data access:
SQLException for SQL [select [...] from CAS_REGISTEREDSERVICE registered0_];
SQL state [42000]; error code [942]; could not execute query; nested exception is org.hibernate.exception.SQLGrammarException: could not execute query
 at org.springframework.orm.hibernate3.SessionFactoryUtils.convertHibernateAccessException(SessionFactoryUtils.java:632)
 at org.springframework.orm.jpa.vendor.HibernateJpaDialect.translateExceptionIfPossible(HibernateJpaDialect.java:95)
 at org.springframework.dao.support.DataAccessUtils.translateIfNecessary(DataAccessUtils.java:212)
 at org.springframework.orm.jpa.JpaAccessor.translateIfNecessary(JpaAccessor.java:152)
 at org.springframework.orm.jpa.JpaTemplate.execute(JpaTemplate.java:189)
 at org.springframework.orm.jpa.JpaTemplate.executeFind(JpaTemplate.java:151)
 at org.springframework.orm.jpa.JpaTemplate.find(JpaTemplate.java:311)
 at org.springframework.orm.jpa.JpaTemplate.find(JpaTemplate.java:307)
 at org.jasig.cas.services.JpaServiceRegistryDaoImpl.load(JpaServiceRegistryDaoImpl.java:30)
 at org.jasig.cas.services.DefaultServicesManagerImpl.load(DefaultServicesManagerImpl.java:134)
 at org.jasig.cas.services.DefaultServicesManagerImpl.<init>(DefaultServicesManagerImpl.java:61)
 at org.jasig.cas.services.DefaultServicesManagerImpl.<init>(DefaultServicesManagerImpl.java:43)
 at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
 at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:39)
 at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:27)
 at java.lang.reflect.Constructor.newInstance(Constructor.java:513)
 at org.springframework.beans.BeanUtils.instantiateClass(BeanUtils.java:100)
 ... 78 more
Caused by: org.springframework.orm.hibernate3.HibernateJdbcException: JDBC exception on Hibernate data access:
SQLException for SQL [select [...] from CAS_REGISTEREDSERVICE registered0_];
SQL state [42000]; error code [942]; could not execute query; nested exception is org.hibernate.exception.SQLGrammarException: could not execute query
 ... 95 more
Caused by: org.hibernate.exception.SQLGrammarException: could not execute query
 at org.hibernate.exception.SQLStateConverter.convert(SQLStateConverter.java:90)
 at org.hibernate.exception.JDBCExceptionHelper.convert(JDBCExceptionHelper.java:66)
 at org.hibernate.loader.Loader.doList(Loader.java:2235)
 at org.hibernate.loader.Loader.listIgnoreQueryCache(Loader.java:2129)
 at org.hibernate.loader.Loader.list(Loader.java:2124)
 at org.hibernate.loader.hql.QueryLoader.list(QueryLoader.java:401)
 at org.hibernate.hql.ast.QueryTranslatorImpl.list(QueryTranslatorImpl.java:363)
 at org.hibernate.engine.query.HQLQueryPlan.performList(HQLQueryPlan.java:196)
 at org.hibernate.impl.SessionImpl.list(SessionImpl.java:1149)
 at org.hibernate.impl.QueryImpl.list(QueryImpl.java:102)
 at org.hibernate.ejb.QueryImpl.getResultList(QueryImpl.java:67)
 at org.springframework.orm.jpa.JpaTemplate$9.doInJpa(JpaTemplate.java:319)
 at org.springframework.orm.jpa.JpaTemplate.execute(JpaTemplate.java:184)
 ... 90 more
Caused by: java.sql.SQLException: ORA-00942: table or view does not exist
 at oracle.jdbc.driver.SQLStateMapping.newSQLException(SQLStateMapping.java:133)
 at oracle.jdbc.driver.DatabaseError.newSQLException(DatabaseError.java:115)
 at oracle.jdbc.driver.DatabaseError.throwSqlException(DatabaseError.java:221)
 at oracle.jdbc.driver.T4CTTIoer.processError(T4CTTIoer.java:467)
 at oracle.jdbc.driver.T4CTTIoer.processError(T4CTTIoer.java:417)
 at oracle.jdbc.driver.T4C8Oall.receive(T4C8Oall.java:1084)
 at oracle.jdbc.driver.T4CPreparedStatement.doOall8(T4CPreparedStatement.java:215)
 at oracle.jdbc.driver.T4CPreparedStatement.executeForDescribe(T4CPreparedStatement.java:1032)
 at oracle.jdbc.driver.T4CPreparedStatement.executeMaybeDescribe(T4CPreparedStatement.java:1139)
 at oracle.jdbc.driver.OracleStatement.doExecuteWithTimeout(OracleStatement.java:1471)
 at oracle.jdbc.driver.OraclePreparedStatement.executeInternal(OraclePreparedStatement.java:3874)
 at oracle.jdbc.driver.OraclePreparedStatement.executeQuery(OraclePreparedStatement.java:3944)
 at oracle.jdbc.driver.OraclePreparedStatementWrapper.executeQuery(OraclePreparedStatementWrapper.java:3613)
 at org.apache.commons.dbcp.DelegatingPreparedStatement.executeQuery(DelegatingPreparedStatement.java:93)
 at org.hibernate.jdbc.AbstractBatcher.getResultSet(AbstractBatcher.java:208)
 at org.hibernate.loader.Loader.getResultSet(Loader.java:1812)
 at org.hibernate.loader.Loader.doQuery(Loader.java:697)
 at org.hibernate.loader.Loader.doQueryAndInitializeNonLazyCollections(Loader.java:259)
 at org.hibernate.loader.Loader.doList(Loader.java:2232)
 ... 100 more

I voluntarily reduce the stack trace for better readability.

With this new information, I can concludes that the missing table is CAS_REGISTEREDSERVICE because this is the only one used in the statement ;).

[spring-projects-issues]

Juergen Hoeller commented

This is a bit of a problem with Hibernate's JDBCException class: It stores context such as the SQL String but doesn't include it in the exception message... As a consequence, I've added that context explicitly when translating those exceptions: directly, without adding another exception to the chain. This should hopefully do the job as well.

Juergen

[spring-projects-issues]

Sébastien Launay commented

Adding another exception to the chain causes the stack to be more difficult to analyze but this was pretty straight forward for exposing:

• SQL string
• SQL state
• error code

In your fix we lose SQL state and error code but i do not know if this kind of information is useful.

Anyway is it possible to see this modification backported in the 2.5.x maintenance branch?

[spring-projects-issues]

Tarun Kothuri commented

This problem is back with Hibernate 4 and Spring 3.2.x
The SQL Statement is not logged and I wonder where it is in the exception chain.