You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@commons.apache.org by "Phil Steitz (JIRA)" <ji...@apache.org> on 2007/01/21 22:56:30 UTC
[jira] Commented: (DBCP-201) Statement closing due to unprovoked
rollback
[ https://issues.apache.org/jira/browse/DBCP-201?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel#action_12466362 ]
Phil Steitz commented on DBCP-201:
----------------------------------
What versions of DBCP and Pool are you running?
> Statement closing due to unprovoked rollback
> --------------------------------------------
>
> Key: DBCP-201
> URL: https://issues.apache.org/jira/browse/DBCP-201
> Project: Commons Dbcp
> Issue Type: Bug
> Affects Versions: 1.3
> Environment: Linux, Hibernate, Java 5, DBCP
> Reporter: Theresa Field
>
> 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)
> **********WORKAROUND**************************
> I think I kind of resolved the symptom although I still feel there are several issues in play here.
> 1. No more statement closed exceptions are being thrown. These exceptions were being thrown because:
> a. Run out of statements\connections in pool (I think that is what is forcing the rollback bc it doesn't happen when the pool is not starved).
> b. Using getCurrentSession() instead of openSession() when using a pool of threads (Quartz and Mule threads). Good advice at http://opensource.atlassian.com/projects/hibernate/browse/HHH-2243 when using hibernate.current_session_context_class=thread for transaction demarcation with plain JDBC for applications with thread pools.
> 2. I tried configuring the whenExhaustedAction for connections and statements, even if I configure 2 to grow the pool for both... these issues still occur when the pool is starved.
> 3. Configuring 20 connection threads and 30 statement threads has resolved the issue (1a) although I don't understand why #2 above does not work. This causes the application to be very volatile especially since you can't tell the statement was closed until you try to set a parameter (not when you prepare the statement)
--
This message is automatically generated by JIRA.
-
If you think it was sent incorrectly contact one of the administrators: https://issues.apache.org/jira/secure/Administrators.jspa
-
For more information on JIRA, see: http://www.atlassian.com/software/jira
---------------------------------------------------------------------
To unsubscribe, e-mail: commons-dev-unsubscribe@jakarta.apache.org
For additional commands, e-mail: commons-dev-help@jakarta.apache.org