[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:34:39 EST 2009
[ http://opensource.atlassian.com/projects/hibernate/browse/HHH-1900?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=32351#action_32351 ]
Nicolas Savois commented on HHH-1900:
-------------------------------------
oups forgot :
to test that functionality, you have to open as much prepared statement as possible.
I was stressing a single functionality of my application, without any result...
when i opened the scope of the test and created as much prepared statement as I could, then the bug appeared.
> 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