[hibernate-issues] [Hibernate-JIRA] Commented: (HHH-1900) Prepared Statement closed before executed by AbstractBatcher - similar to HHH-876
Nicolas Savois (JIRA)
noreply at atlassian.com
Tue Feb 10 07:30:38 EST 2009
[ http://opensource.atlassian.com/projects/hibernate/browse/HHH-1900?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=32350#action_32350 ]
Nicolas Savois commented on HHH-1900:
-------------------------------------
It was DBCP which was creating the bug...
the poolPreparedStatements of DBCP is bugged... we simply disabled the functionality and everything went back to normal.
we also tried another connection pool, aka OracleDataSource which also work pretty fine (the configuration is quite complexe though)
for me is was not an hibernate bug
> Prepared Statement closed before executed by AbstractBatcher - similar to HHH-876
> ---------------------------------------------------------------------------------
>
> Key: HHH-1900
> URL: http://opensource.atlassian.com/projects/hibernate/browse/HHH-1900
> Project: Hibernate Core
> Issue Type: Bug
> Components: core
> Affects Versions: 3.1.3
> Environment: hibernate 3.1.3, MS SQL Server, Apache DBCP, JSQLConnect
> Reporter: Greg Burcher
> Priority: Critical
>
> Using Hibernate v3.1.3, I am experiencing symptoms that sound like bug HHH-876. Problem has been intermittent, may be related to timing/latency. Problem happens less frequently when lots of hibernate debug logging is turned on. Using JDBC drivers from jnetdirect, get com.jnetdirect.jsql.JSQLException with message of "The statement is closed".
> Failure occurs on a variety of queries, but only occasionally for any given query. Once the problem has occurred for a particular query (prepared statement), problem will occur every time from that point on for that query.
> Here is debug trace pattern of successful query:
> 10:05:40,099 DEBUG AbstractBatcher:311 - about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
> 10:05:40,099 DEBUG ConnectionManager:358 - opening JDBC connection
> 10:05:40,109 DEBUG DBCPConnectionProvider:? - active: 1 (max: 20) idle: 0(max: 20)
> Hibernate: select this_.id as id27_0_, this_.language as language27_0_, this_.enabled as enabled27_0_, this_.sourceID as sourceID27_0_, this_.focusQuestion as focusQue5_27_0_, this_.markedFocusQuestion as markedFo6_27_0_ from WebInquiryFocusQuestion this_ where this_.id=? and this_.enabled=? and this_.language=?
> 10:05:40,109 DEBUG AbstractBatcher:424 - preparing statement
> 10:05:40,109 DEBUG AbstractBatcher:327 - about to open ResultSet (open ResultSets: 0, globally: 0)
> 10:05:40,109 DEBUG AbstractBatcher:334 - about to close ResultSet (open ResultSets: 1, globally: 1)
> 10:05:40,109 DEBUG AbstractBatcher:319 - about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
> 10:05:40,109 DEBUG AbstractBatcher:470 - closing statement
> 10:05:40,119 DEBUG JDBCContext:213 - after autocommit
> 10:05:40,119 DEBUG ConnectionManager:341 - aggressively releasing JDBC connection
> 10:05:40,119 DEBUG ConnectionManager:378 - releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
> 10:05:40,119 DEBUG DBCPConnectionProvider:? - active: 0 (max: 20) idle: 1(max: 20)
> versus trace when error occurs:
> 10:05:41,481 DEBUG AbstractBatcher:311 - about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
> 10:05:41,481 DEBUG ConnectionManager:358 - opening JDBC connection
> 10:05:41,481 DEBUG DBCPConnectionProvider:? - active: 1 (max: 20) idle: 0(max: 20)
> Hibernate: select this_.id as id27_0_, this_.language as language27_0_, this_.enabled as enabled27_0_, this_.sourceID as sourceID27_0_, this_.focusQuestion as focusQue5_27_0_, this_.markedFocusQuestion as markedFo6_27_0_ from WebInquiryFocusQuestion this_ where this_.id=? and this_.enabled=? and this_.language=?
> 10:05:41,481 DEBUG AbstractBatcher:424 - preparing statement
> 10:05:41,481 DEBUG AbstractBatcher:319 - about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
> 10:05:41,481 DEBUG AbstractBatcher:470 - closing statement
> 10:05:41,501 WARN JDBCExceptionReporter:71 - SQL Error: 0, SQLState: null
> 10:05:41,501 ERROR JDBCExceptionReporter:72 - The statement is closed
> 10:05:41,511 DEBUG JDBCContext:213 - after autocommit
> 10:05:41,511 DEBUG ConnectionManager:341 - aggressively releasing JDBC connection
> 10:05:41,511 DEBUG ConnectionManager:378 - releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
> 10:05:41,511 DEBUG DBCPConnectionProvider:? - active: 0 (max: 20) idle: 1(max: 20)
> 10:05:41,511 DEBUG ConnectionManager:312 - connection already null in cleanup : no action
> Partial stack trace:
> [0] com.jnetdirect.jsql.JSQLException.makeFromDriverError:70 (in file JSQLException.java)
> [1] com.jnetdirect.jsql.JSQLStatement.setParam:1223 (in file JSQLStatement.java)
> [2] com.jnetdirect.jsql.JSQLPreparedStatement.setInt:693 (in file JSQLPreparedStatement.java)
> [3] org.apache.commons.dbcp.DelegatingPreparedStatement.setInt:116 (in file DelegatingPreparedStatement.java)
> [4] org.apache.commons.dbcp.DelegatingPreparedStatement.setInt:116 (in file DelegatingPreparedStatement.java)
> [5] org.hibernate.type.IntegerType.set:41 (in file IntegerType.java)
> [6] org.hibernate.type.NullableType.nullSafeSet:85 (in file NullableType.java)
> [7] org.hibernate.type.NullableType.nullSafeSet:63 (in file NullableType.java)
> [8] org.hibernate.loader.Loader.bindPositionalParameters:1514 (in file Loader.java)
> [9] org.hibernate.loader.Loader.prepareQueryStatement:1576 (in file Loader.java)
> [10] org.hibernate.loader.Loader.doQuery:661 (in file Loader.java)
> [11] org.hibernate.loader.Loader.doQueryAndInitializeNonLazyCollections:224 (in file Loader.java)
> [12] org.hibernate.loader.Loader.doList:2145 (in file Loader.java)
> [13] org.hibernate.loader.Loader.listIgnoreQueryCache:2029 (in file Loader.java)
> [14] org.hibernate.loader.Loader.list:2024 (in file Loader.java)
> [15] org.hibernate.loader.criteria.CriteriaLoader.list:94 (in file CriteriaLoader.java)
> [16] org.hibernate.impl.SessionImpl.list:1552 (in file SessionImpl.java)
> [17] org.hibernate.impl.CriteriaImpl.list:283 (in file CriteriaImpl.java)
> [18] org.hibernate.impl.CriteriaImpl.uniqueResult:305 (in file CriteriaImpl.java)
> Stack trace will differ depending on which query triggers the problem.
--
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.jspa
-
For more information on JIRA, see: http://www.atlassian.com/software/jira
More information about the hibernate-issues
mailing list