[hibernate-issues] [Hibernate-JIRA] Commented: (HHH-2243) Statement closing due to unprovoked rollback
Theresa (JIRA)
noreply at atlassian.com
Tue Nov 21 18:01:04 EST 2006
[ http://opensource.atlassian.com/projects/hibernate/browse/HHH-2243?page=comments#action_25397 ]
Theresa commented on HHH-2243:
------------------------------
Perhaps I shouldn't have asked about the other JIRA because it actually seems unrelated.
I did describe the issues and I did isolate the problems. There seems to be a disconnect between configuration and functionality. The issues are with the whenExchaustedAction. The pool does not grow nor does threads wait for a free connection if the pool runs out of threads. This seems like a completely superfluous configuration since what happens (for Postgres) is that you end up getting JDBC exceptions from the Postgres driver stating that the statement has been closed when you try to execute the query. This happens for Hibernate and plain JDBC code. This doesn't happen for all connection pools or DB implementations. It is a problem with Hibernate or DBCP. I have also opened a JIRA with DBCP in case this happens to be a problem with their implementation.
> 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)
--
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