[hibernate-issues] [Hibernate-JIRA] Commented: (HHH-2243) Statement closing due to unprovoked rollback

Statement closing due to unprovoked rollback -------------------------------------------- Key: HHH-2243 URL: http://opensource.atlassian.com/projects/hibernate/browse/HHH-2243 Project: Hibernate3 Type: Bug

Components: core Versions: 3.1.3 Environment: postgresql, hibernate 3.1.3, and apache DBCP Reporter: Theresa

Has there been a resolution to the issue described at http://opensource.atlassian.com/projects/hibernate/browse/HHH-876? I have seen closed statement errors sporadically occurring and I can't get it under control. Even when the last execution of the statement is successful in a recursive loop reusing the statement, I can still see this happen. The stack and code is below. I am very curious how the rollback is getting called. There are several more places in the code where this is occurring. It is odd that it only happens sporadically and I have only identified 2 places out of a couple of dozen that actually causes this to occur. **************CONFIG******************** <?xml version="1.0" encoding="UTF-8"?> <!DOCTYPE hibernate-configuration PUBLIC "-//Hibernate/Hibernate Configuration DTD 3.0//EN" "http://hibernate.sourceforge.net/hibernate-configuration-3.0.dtd"> <hibernate-configuration> <session-factory> <property name="hibernate.connection.driver_class">org.postgresql.Driver</property> <property name="hibernate.connection.password">password</property> <property name="hibernate.connection.url">jdbc:postgresql://localhost/myDB</property> <property name="hibernate.connection.username">user</property> <property name="hibernate.dialect">org.hibernate.dialect.PostgreSQLDialect</property> <property name="hibernate.transaction.factory_class ">org.hibernate.transaction.JDBCTransactionFactory</property> <property name="hibernate.current_session_context_class">thread</property> <property name="hibernate.connection.provider_class">org.hibernate.connection.DBCPConnectionProvider</property> <!-- Not specified with 3rd party connection pool <property name="connection.pool_size">20</property>--> <property name="hibernate.dbcp.maxActive">3</property> <property name="hibernate.dbcp.maxIdle">3</property> <property name="hibernate.dbcp.max Wait">60000</property> <property name="hibernate.dbcp.whenExhaustedAction">1</property> <property name="hibernate.dbcp.ps.maxActive">3</property> <property name="hibernate.dbcp.ps.maxIdle">3</property> <property name="hibernate.dbcp.ps.maxWait">1000*20</property> <property name="hibernate.dbcp.ps.whenExhaustedAction">1</property> <property name="hibernate.connection.release_mode">after_transaction</property> <property name="hibernate.dbcp.poolPreparedStatements">true</property> </session-factory> </hibernate-configuration> ********************CODE************** private synchronized HashMap<Integer, LeadDeliveryPreferences> queryForPreferences() throws SQLException{ // we open a session because this quartz group seems to have an // issue retrieving the session on the first job execution Session hibSession = HibernateUtil.getSessionFactory().openSession(); hibSession.beginTransaction(); Connection conn = hibSession.connection(); HashMap<Integer, LeadDeliveryPreferences> allMap = new HashMap<Integer, LeadDeliveryPreferences>(); try{ PreparedStatement stmt = conn.prepareStatement(QUERY_ALL_PREF); ResultSet rs = stmt.executeQuery(); //Query for lead delivery preferences while(rs.next()){ LeadDeliveryPreferences lp = new LeadDeliveryPreferences(); lp.setCampaignID(rs.getInt(LeadDeliveryPreferences.DB_CAMPAIGN_ID)); lp.setCronSchedule(rs.getString(LeadDeliveryPreferences.DB_CRON_SCHEDULE)); lp.setEmail(rs.getString(LeadDeliveryPreferences.DB_EMAIL)); lp.setDeliveryEnabled(rs.getBoolean(LeadDeliveryPreferences.DB_DELIVERY_ENABLED)); lp.setDeliveryTransformer(rs.getString(LeadDeliveryPreferences.DB_DELIVERY_TRANSFORMER)); lp.setReportEnabled(rs.getBoolean(LeadDeliveryPreferences.DB_REPORT_ENABLED)); lp.setReportType(rs.getString(LeadDeliveryPreferences.DB_REPORT_TYPE)); lp.setSource(rs.getString(LeadDeliveryPreferences.DB_SOURCE)); allMap.put(rs.getInt(LeadDeliveryPreferences.DB_CAMPAIGN_ID), lp); log_.debug("Picked up schedule for campaign: " + rs.getInt(LeadDeliveryPreferences.DB_CAMPAIGN_ID)); } //prepare statement object for re-use //stmt.clearParameters(); //Query for crosswalk values Iterator it = allMap.keySet().iterator(); ArrayList<Integer> idList = new ArrayList<Integer>(); while(it.hasNext()){ idList.add((Integer)it.next()); } PreparedStatement stmt2 = conn.prepareStatement(QUERY_TRANSLATIONS); for(int i=0;i<idList.size();i++){ log_.debug("Getting crosswalk for --> " + idList.get(i)); stmt2.setInt(1,idList.get(i)); ResultSet rs2 = stmt2.executeQuery(); LeadDeliveryPreferences lp = allMap.get(idList.get(i)); while(rs2.next()){ LeadCrosswalk lc = new LeadCrosswalk(); log_.debug("got key --> " + rs2.getString(LeadCrosswalk.DB_NAME_COL_NM)); lc.setName(rs2.getString(LeadCrosswalk.DB_NAME_COL_NM)); lc.setIsMethod(rs2.getBoolean(LeadCrosswalk.DB_IS_METHOD_COL_NM)); lc.setNameTranslation(rs2.getString(LeadCrosswalk.DB_NAME_TRANSLATION_COL_NM)); lc.setIsRequired(rs2.getBoolean(LeadCrosswalk.DB_IS_REQUIRED_COL_NM)); lp.addCrosswalk(lc.getName(), lc); } // prepare statement object for re-use stmt2.clearParameters(); allMap.remove(idList.get(i)); allMap.put(idList.get(i), lp); } //Query for phone ranges PreparedStatement stmt3 = conn.prepareStatement(QUERY_PHONE_RANGES); for(int i=0;i<idList.size();i++){ stmt3.setInt(1, idList.get(i)); rs = stmt3.executeQuery(); LeadDeliveryPreferences lp = allMap.get(idList.get(i)); while(rs.next()){ LeadDeliveryClientPhoneRanges phoneRange = new LeadDeliveryClientPhoneRanges(); phoneRange.setLow(rs.getInt(LeadDeliveryClientPhoneRanges.DB_LOW)); phoneRange.setHigh(rs.getInt(LeadDeliveryClientPhoneRanges.DB_HIGH)); phoneRange.setLabel(rs.getString(LeadDeliveryClientPhoneRanges.DB_LABEL)); log_.debug("Added phone range " + phoneRange.getLabel()); lp.addPhoneRange(phoneRange); } allMap.remove(idList.get(i)); allMap.put(idList.get(i), lp); } hibSession.getTransaction().commit(); } catch(SQLException se){ hibSession.getTransaction().rollback(); log_.error("SQLException occured querying for crosswalk", se); RuntimeErrorEmailHelper.addMessage("Error creating cron trigger"); throw se; } return allMap; } ****************STACK****************** 2006-11-15 13:56:02,892 [DefaultQuartzScheduler_Worker-8] DEBUG leads.delivery.LeadDeliveryPreferencesService - Getting crosswalk for --> 200 2006-11-15 13:56:02,899 [DefaultQuartzScheduler_Worker-8] DEBUG hibernate.transaction.JDBCTransaction - rollback 2006-11-15 13:56:02,912 [DefaultQuartzScheduler_Worker-8] DEBUG hibernate.transaction.JDBCTransaction - rolled back JDBC Connection 2006-11-15 13:56:02,912 [DefaultQuartzScheduler_Worker-8] DEBUG hibernate.jdbc.JDBCContext - after transaction completion 2006-11-15 13:56:02,912 [DefaultQuartzScheduler_Worker-8] DEBUG hibernate.jdbc.ConnectionManager - aggressively releasing JDBC connection 2006-11-15 13:56:02,912 [DefaultQuartzScheduler_Worker-8] DEBUG hibernate.jdbc.ConnectionManager - releasing JDBC connection [ (open PreparedStatements: 0, globally: 1) (open ResultSets: 0, globally: 0)] 2006-11-15 13:56:02,913 [DefaultQuartzScheduler_Worker-8] INFO hibernate.connection.DBCPConnectionProvider - active: 3 (max: 3) idle: 0(max: 3) 2006-11-15 13:56:02,913 [DefaultQuartzScheduler_Worker-8] DEBUG hibernate.impl.SessionImpl - after transaction completion 2006-11-15 13:56:02,915 [DefaultQuartzScheduler_Worker-8] ERROR leads.delivery.LeadDeliveryPreferencesService - SQLException occured querying for crosswalk 2006-11-15 13:56:02,920 [DefaultQuartzScheduler_Worker-8] INFO quartz.core.JobRunShell - Job LEAD_PREFERENCES.PREFERENCES_UPDATE_JOB threw a JobExecutionException: org.quartz.JobExecutionException: org.postgresql.util.PSQLException: This statement has been closed. [See nested exception: org.postgresql.util.PSQLExcepti on: This statement has been closed.] at com.tippit.service.leads.delivery.LeadDeliveryPreferencesService.execute(LeadDeliveryPreferencesService.java:185) at org.quartz.core.JobRunShell.run(JobRunShell.java:195) at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:520) * Nested Exception (Underlying Cause) --------------- org.postgresql.util.PSQLException: This statement has been closed. at org.postgresql.jdbc2.AbstractJdbc2Statement.checkClosed(AbstractJdbc2Statement.java:2308) at org.postgresql.jdbc2.AbstractJdbc2Statement.setInt(AbstractJdbc2Statement.java:1070) at org.apache.commons.dbcp.DelegatingPreparedStatement.setInt(DelegatingPreparedStatement.java:116) at org.apache.commons.dbcp.DelegatingPreparedStatement.setInt(DelegatingPreparedStatement.java:116) at com.tippit.service.leads.delivery.LeadDeliveryPreferencesService.queryForPreferences(LeadDeliveryPreferencesService.java:116) at com.tippit.service.leads.delivery.LeadDeliveryPreferencesService.load(LeadDeliveryPreferencesService.java:61) at com.tippit.service.leads.delivery.LeadDeliveryPreferencesService.execute(LeadDeliveryPreferencesService.java:181) at org.quartz.core.JobRunShell.run(JobRunShell.java:195) at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:520)