our system is a pretty low load system. i am in the process of writing junit tests that perform regression testing. my problem is when the test runs, it really pounds the hibernate system validating that the correct data was written to the database. it gets about 7 or 8 queries into the process and locks up. i have to reboot jboss to get it to unlock. all i get in the log is this
2007-09-07 18:40:58,233 http-localhost%2F127.0.0.1-8080-1 DEBUG appLog - Interface Manager selected xml trans: DbQuery
2007-09-07 18:40:58,233 http-localhost%2F127.0.0.1-8080-1 DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Returning cached instance of singleton bean 'configDAO'
2007-09-07 18:40:58,234 http-localhost%2F127.0.0.1-8080-1 DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Creating instance of bean 'dbUtil' with merged definition [Root bean: class [com.show.hub.util.DbUtil]; abstract=false; singleton=false; lazyInit=false; autowire=0; dependencyCheck=0; initMethodName=null; destroyMethodName=null; factoryMethodName=null; factoryBeanName=null; defined in ServletContext resource [/WEB-INF/classes/applicationContext.xml]]
2007-09-07 18:40:58,234 http-localhost%2F127.0.0.1-8080-1 DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Invoking BeanPostProcessors before instantiation of bean 'dbUtil'
2007-09-07 18:40:58,234 http-localhost%2F127.0.0.1-8080-1 DEBUG org.springframework.beans.CachedIntrospectionResults - Using cached introspection results for class [com.show.hub.util.DbUtil]
2007-09-07 18:40:58,234 http-localhost%2F127.0.0.1-8080-1 DEBUG org.springframework.beans.factory.support.BeanDefinitionValueResolver - Resolving reference from property 'dataSource' in bean 'dbUtil' to bean 'dataSource'
2007-09-07 18:40:58,235 http-localhost%2F127.0.0.1-8080-1 DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Returning cached instance of singleton bean 'dataSource'
2007-09-07 18:40:58,235 http-localhost%2F127.0.0.1-8080-1 DEBUG org.springframework.beans.factory.support.BeanDefinitionValueResolver - Resolving reference from property 'configDAO' in bean 'dbUtil' to bean 'configDAO'
2007-09-07 18:40:58,235 http-localhost%2F127.0.0.1-8080-1 DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Returning cached instance of singleton bean 'configDAO'
2007-09-07 18:40:58,235 http-localhost%2F127.0.0.1-8080-1 DEBUG org.springframework.beans.BeanWrapperImpl - About to invoke write method [public void com.show.hub.util.DbUtil.setDataSource(javax.sql.DataSource)] on object of class [com.show.hub.util.DbUtil]
2007-09-07 18:40:58,235 http-localhost%2F127.0.0.1-8080-1 DEBUG org.springframework.beans.BeanWrapperImpl - Invoked write method [public void com.show.hub.util.DbUtil.setDataSource(javax.sql.DataSource)] with value of type [javax.sql.DataSource]
2007-09-07 18:40:58,235 http-localhost%2F127.0.0.1-8080-1 DEBUG org.springframework.beans.BeanWrapperImpl - About to invoke write method [public void com.show.hub.util.DbUtil.setConfigDAO(com.show.hub.dao.hibernate.ConfigDAO)] on object of class [com.show.hub.util.DbUtil]
2007-09-07 18:40:58,235 http-localhost%2F127.0.0.1-8080-1 DEBUG org.springframework.beans.BeanWrapperImpl - Invoked write method [public void com.show.hub.util.DbUtil.setConfigDAO(com.show.hub.dao.hibernate.ConfigDAO)] with value of type [com.show.hub.dao.hibernate.ConfigDAO]
2007-09-07 18:40:58,236 http-localhost%2F127.0.0.1-8080-1 DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Invoking BeanPostProcessors before initialization of bean 'dbUtil'
2007-09-07 18:40:58,236 http-localhost%2F127.0.0.1-8080-1 DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Invoking BeanPostProcessors after initialization of bean 'dbUtil'
2007-09-07 18:40:58,236 http-localhost%2F127.0.0.1-8080-1 DEBUG org.springframework.orm.hibernate3.SessionFactoryUtils - Opening Hibernate Session
2007-09-07 18:40:58,236 http-localhost%2F127.0.0.1-8080-1 DEBUG org.hibernate.impl.SessionImpl - opened session at timestamp: 11892048582
2007-09-07 18:40:58,237 http-localhost%2F127.0.0.1-8080-1 DEBUG org.hibernate.engine.query.QueryPlanCache - located HQL query plan in cache (from Config config where config.configName='hub_demo_mode')
2007-09-07 18:40:58,237 http-localhost%2F127.0.0.1-8080-1 DEBUG org.hibernate.engine.query.QueryPlanCache - located HQL query plan in cache (from Config config where config.configName='hub_demo_mode')
2007-09-07 18:40:58,237 http-localhost%2F127.0.0.1-8080-1 DEBUG org.hibernate.engine.query.HQLQueryPlan - find: from Config config where config.configName='hub_demo_mode'
2007-09-07 18:40:58,237 http-localhost%2F127.0.0.1-8080-1 DEBUG org.hibernate.engine.QueryParameters - named parameters: {}
2007-09-07 18:40:58,237 http-localhost%2F127.0.0.1-8080-1 DEBUG org.hibernate.jdbc.AbstractBatcher - about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
2007-09-07 18:40:58,237 http-localhost%2F127.0.0.1-8080-1 DEBUG org.hibernate.jdbc.ConnectionManager - opening JDBC connection
2007-09-07 18:42:22,435 Thread-6 DEBUG com.arjuna.ats.arjuna.logging.arjLogger - Periodic recovery - first pass <Fri, 7 Sep 2007 18:42:22>
2007-09-07 18:42:22,436 Thread-6 DEBUG com.arjuna.ats.arjuna.logging.arjLogger - StatusModule: first pass
2007-09-07 18:42:22,437 Thread-6 DEBUG com.arjuna.ats.txoj.logging.txojLoggerI18N - [com.arjuna.ats.internal.txoj.recovery.TORecoveryModule_3] - TORecoveryModule - first pass
2007-09-07 18:42:22,437 Thread-6 DEBUG com.arjuna.ats.jta.logging.loggerI18N - [com.arjuna.ats.internal.jta.recovery.info.firstpass] Local XARecoveryModule - first pass
2007-09-07 18:42:32,443 Thread-6 DEBUG com.arjuna.ats.arjuna.logging.arjLogger - Periodic recovery - second pass <Fri, 7 Sep 2007 18:42:32>
2007-09-07 18:42:32,444 Thread-6 DEBUG com.arjuna.ats.arjuna.logging.arjLogger - AtomicActionRecoveryModule: Second pass
2007-09-07 18:42:32,444 Thread-6 DEBUG com.arjuna.ats.txoj.logging.txojLoggerI18N - [com.arjuna.ats.internal.txoj.recovery.TORecoveryModule_6] - TORecoveryModule - second pass
2007-09-07 18:42:32,444 Thread-6 DEBUG com.arjuna.ats.jta.logging.loggerI18N - [com.arjuna.ats.internal.jta.recovery.info.secondpass] Local XARecoveryModule - second pass
when i initiate the shutdown, i get this
2007-09-07 18:42:36,084 http-localhost%2F127.0.0.1-8080-1 DEBUG org.hibernate.jdbc.JDBCContext - after autocommit
2007-09-07 18:42:36,084 http-localhost%2F127.0.0.1-8080-1 DEBUG org.hibernate.jdbc.ConnectionManager - transaction completed on session with on_close connection release mode; be sure to close the session to release JDBC resources!
2007-09-07 18:42:36,085 http-localhost%2F127.0.0.1-8080-1 DEBUG org.hibernate.impl.SessionImpl - after transaction completion
2007-09-07 18:42:36,085 http-localhost%2F127.0.0.1-8080-1 DEBUG org.springframework.orm.hibernate3.SessionFactoryUtils - Closing Hibernate Session
2007-09-07 18:42:36,085 http-localhost%2F127.0.0.1-8080-1 DEBUG org.hibernate.impl.SessionImpl - closing session
2007-09-07 18:42:36,085 http-localhost%2F127.0.0.1-8080-1 DEBUG org.hibernate.jdbc.ConnectionManager - connection already null in cleanup : no action
2007-09-07 18:42:36,086 http-localhost%2F127.0.0.1-8080-1 ERROR STDERR - java.lang.IllegalStateException: Pool not open
2007-09-07 18:42:36,088 http-localhost%2F127.0.0.1-8080-1 ERROR STDERR - at org.apache.commons.pool.BaseObjectPool.assertOpen(BaseObjectPool.java:78)
2007-09-07 18:42:36,088 http-localhost%2F127.0.0.1-8080-1 ERROR STDERR - at org.apache.commons.pool.impl.GenericObjectPool.borrowObject(GenericObjectPool.java:722)
2007-09-07 18:42:36,089 http-localhost%2F127.0.0.1-8080-1 ERROR STDERR - at org.apache.commons.dbcp.PoolingDataSource.getConnection(PoolingDataSource.java:95)
2007-09-07 18:42:36,089 http-localhost%2F127.0.0.1-8080-1 ERROR STDERR - at org.apache.commons.dbcp.BasicDataSource.getConnection(BasicDataSource.java:540)
2007-09-07 18:42:36,089 http-localhost%2F127.0.0.1-8080-1 ERROR STDERR - at org.springframework.orm.hibernate3.LocalDataSourceConnectionProvider.getConnection(LocalDataSourceConnectionProvider.java:80)
2007-09-07 18:42:36,089 http-localhost%2F127.0.0.1-8080-1 ERROR STDERR - at org.hibernate.jdbc.ConnectionManager.openConnection(ConnectionManager.java:423)
2007-09-07 18:42:36,089 http-localhost%2F127.0.0.1-8080-1 ERROR STDERR - at org.hibernate.jdbc.ConnectionManager.getConnection(ConnectionManager.java:144)
2007-09-07 18:42:36,090 http-localhost%2F127.0.0.1-8080-1 ERROR STDERR - at org.hibernate.jdbc.AbstractBatcher.prepareQueryStatement(AbstractBatcher.java:139)
2007-09-07 18:42:36,090 http-localhost%2F127.0.0.1-8080-1 ERROR STDERR - at org.hibernate.loader.Loader.prepareQueryStatement(Loader.java:1547)
2007-09-07 18:42:36,090 http-localhost%2F127.0.0.1-8080-1 ERROR STDERR - at org.hibernate.loader.Loader.doQuery(Loader.java:673)
2007-09-07 18:42:36,090 http-localhost%2F127.0.0.1-8080-1 ERROR STDERR - at org.hibernate.loader.Loader.doQueryAndInitializeNonLazyCollections(Loader.java:236)
2007-09-07 18:42:36,090 http-localhost%2F127.0.0.1-8080-1 ERROR STDERR - at org.hibernate.loader.Loader.doList(Loader.java:2220)
2007-09-07 18:42:36,091 http-localhost%2F127.0.0.1-8080-1 ERROR STDERR - at org.hibernate.loader.Loader.listIgnoreQueryCache(Loader.java:2104)
2007-09-07 18:42:36,091 http-localhost%2F127.0.0.1-8080-1 ERROR STDERR - at org.hibernate.loader.Loader.list(Loader.java:2099)
2007-09-07 18:42:36,091 http-localhost%2F127.0.0.1-8080-1 ERROR STDERR - at org.hibernate.loader.hql.QueryLoader.list(QueryLoader.java:378)
2007-09-07 18:42:36,091 http-localhost%2F127.0.0.1-8080-1 ERROR STDERR - at org.hibernate.hql.ast.QueryTranslatorImpl.list(QueryTranslatorImpl.java:338)
2007-09-07 18:42:36,092 http-localhost%2F127.0.0.1-8080-1 ERROR STDERR - at org.hibernate.engine.query.HQLQueryPlan.performList(HQLQueryPlan.java:172)
2007-09-07 18:42:36,092 http-localhost%2F127.0.0.1-8080-1 ERROR STDERR - at org.hibernate.impl.SessionImpl.list(SessionImpl.java:1121)
2007-09-07 18:42:36,092 http-localhost%2F127.0.0.1-8080-1 ERROR STDERR - at org.hibernate.impl.QueryImpl.list(QueryImpl.java:79)
2007-09-07 18:42:36,092 http-localhost%2F127.0.0.1-8080-1 ERROR STDERR - at org.springframework.orm.hibernate3.HibernateTemplate$29.doInHibernate(HibernateTemplate.java:826)
2007-09-07 18:42:36,092 http-localhost%2F127.0.0.1-8080-1 ERROR STDERR - at org.springframework.orm.hibernate3.HibernateTemplate.execute(HibernateTemplate.java:365)
2007-09-07 18:42:36,093 http-localhost%2F127.0.0.1-8080-1 ERROR STDERR - at org.springframework.orm.hibernate3.HibernateTemplate.find(HibernateTemplate.java:817)
2007-09-07 18:42:36,093 http-localhost%2F127.0.0.1-8080-1 ERROR STDERR - at org.springframework.orm.hibernate3.HibernateTemplate.find(HibernateTemplate.java:809)
2007-09-07 18:42:36,093 http-localhost%2F127.0.0.1-8080-1 ERROR STDERR - at com.show.hub.dao.hibernate.ConfigDAO.getByConfigName(ConfigDAO.java:85)
2007-09-07 18:42:36,093 http-localhost%2F127.0.0.1-8080-1 ERROR STDERR - at com.show.hub.manager.DBQueryManager.processXMLRequest(DBQueryManager.java:45)
2007-09-07 18:42:36,093 http-localhost%2F127.0.0.1-8080-1 ERROR STDERR - at com.show.hub.manager.InterfaceManager.routeXMLRequest(InterfaceManager.java:57)
2007-09-07 18:42:36,093 http-localhost%2F127.0.0.1-8080-1 ERROR STDERR - at com.show.hub.web.Interface.service(Interface.java:68)
2007-09-07 18:42:36,094 http-localhost%2F127.0.0.1-8080-1 ERROR STDERR - at javax.servlet.http.HttpServlet.service(HttpServlet.java:803)
2007-09-07 18:42:36,094 http-localhost%2F127.0.0.1-8080-1 ERROR STDERR - at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:290)
2007-09-07 18:42:36,094 http-localhost%2F127.0.0.1-8080-1 ERROR STDERR - at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
2007-09-07 18:42:36,094 http-localhost%2F127.0.0.1-8080-1 ERROR STDERR - at org.jboss.web.tomcat.filters.ReplyHeaderFilter.doFilter(ReplyHeaderFilter.java:96)
2007-09-07 18:42:36,094 http-localhost%2F127.0.0.1-8080-1 ERROR STDERR - at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235)
2007-09-07 18:42:36,095 http-localhost%2F127.0.0.1-8080-1 ERROR STDERR - at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
2007-09-07 18:42:36,095 http-localhost%2F127.0.0.1-8080-1 ERROR STDERR - at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:230)
2007-09-07 18:42:36,095 http-localhost%2F127.0.0.1-8080-1 ERROR STDERR - at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:175)
2007-09-07 18:42:36,095 http-localhost%2F127.0.0.1-8080-1 ERROR STDERR - at org.jboss.web.tomcat.security.SecurityAssociationValve.invoke(SecurityAssociationValve.java:179)
2007-09-07 18:42:36,095 http-localhost%2F127.0.0.1-8080-1 ERROR STDERR - at org.jboss.web.tomcat.security.JaccContextValve.invoke(JaccContextValve.java:84)
2007-09-07 18:42:36,096 http-localhost%2F127.0.0.1-8080-1 ERROR STDERR - at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:128)
2007-09-07 18:42:36,096 http-localhost%2F127.0.0.1-8080-1 ERROR STDERR - at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:104)
2007-09-07 18:42:36,096 http-localhost%2F127.0.0.1-8080-1 ERROR STDERR - at org.jboss.web.tomcat.service.jca.CachedConnectionValve.invoke(CachedConnectionValve.java:157)
2007-09-07 18:42:36,096 http-localhost%2F127.0.0.1-8080-1 ERROR STDERR - at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109)
2007-09-07 18:42:36,096 http-localhost%2F127.0.0.1-8080-1 ERROR STDERR - at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:241)
2007-09-07 18:42:36,097 http-localhost%2F127.0.0.1-8080-1 ERROR STDERR - at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:844)
2007-09-07 18:42:36,097 http-localhost%2F127.0.0.1-8080-1 ERROR STDERR - at org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.process(Http11Protocol.java:580)
2007-09-07 18:42:36,097 http-localhost%2F127.0.0.1-8080-1 ERROR STDERR - at org.apache.tomcat.util.net.JIoEndpoint$Worker.run(JIoEndpoint.java:447)
2007-09-07 18:42:36,097 http-localhost%2F127.0.0.1-8080-1 ERROR STDERR - at java.lang.Thread.run(Thread.java:595)
2007-09-07 18:42:36,097 http-localhost%2F127.0.0.1-8080-1 INFO appLog - Interface RESPONSE XML :
exactly when it occures isn't really sure, it happens on about the 7th or 8th transaction that i use, but where it occures is always the same. i am opening a DAO object to see if the system is in test mode.
i dont even know where to begin on this. i upgraded my version of hibernate to the latest with no help. im running jboss-4.2.1.GA and java build 1.5.0_11-b03
|