[
https://issues.apache.org/jira/browse/DBCP-201?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel#action_12525745
]
Henri Yandell commented on DBCP-201:
------------------------------------
There's a bit more info on this in the comments at:
http://opensource.atlassian.com/projects/hibernate/browse/HHH-2243
This issue feels a bit like DBCP-212, though that's connection so maybe not.
> 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.2.1
> Environment: Linux, Hibernate, Java 5, DBCP
> Reporter: Theresa Field
> Fix For: 1.3
>
>
> 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.
-
You can reply to this email to add a comment to the issue online.
