Random
monkeyden Nov 7, 2007 2:21 PMSeam 1.2.1GA
JBoss AS 4.0.5
We're running some JMeter tests on our Seam application. We have been seeing random "Transaction not active" errors after the tests have been running for a while. I say "random" because they don't relate to a specific screen or piece of code. They can appear in any functionality which uses one of our SMPC connections. They also don't appear to be associated strictly with read/write pages, since they can be found on simple searches.
We are having some trouble isolating the problem, as it seems to be related to the reuse of an invalid connection and/or transaction.
First, has anyone seen these types of transaction issues using SMPC, and second, how might we go about determining where specifically it manifests itself. I mention SMPC only because most of our app relies on the implicit trasnactions of TransactionSeamPhaseListener but we also have explicit transactions in a separate thread.
Note: I inquired about the explicit transactions piece in the following thread:
http://www.jboss.com/index.html?module=bb&op=viewtopic&t=118996
Here is an example of the stack trace. Pay no attention to the FATAL log level. I did this just to keep all other logging quiet.
12:59:01,091 FATAL [PropertySearchAction] 1791206254 - Total time to run PropertySearch.loadPage(): 1329 12:59:01,419 FATAL [PropertySearchAction] 492990855 - Total time to run PropertySearch.loadPage(): 75907 12:59:01,981 FATAL [PropertySearchAction] 939675135 - Total time to run PropertySearch.loadPage(): 77390 12:59:02,137 FATAL [PropertySearchAction] 2040933307 - Total time to run PropertySearch.loadPage(): 1734 12:59:26,137 ERROR [[Faces Servlet]] Servlet.service() for servlet Faces Servlet threw exception javax.faces.el.PropertyNotFoundException: /includes/advanced-search-form/more-search-options.xhtml @16,89 value="#{actio n.searchCriteria.minGrossLivingArea}": Bean: com.nemoves.pws.actions.associatesearch.AssociateQuickSearch_$$_javassist_1 10, property: searchCriteria at com.sun.facelets.el.LegacyValueBinding.getValue(LegacyValueBinding.java:58) at javax.faces.component.UIOutput.getValue(UIOutput.java:77) at javax.faces.component.UIInput.validate(UIInput.java:357) at javax.faces.component.UIInput.processValidators(UIInput.java:183) at javax.faces.component.UIComponentBase.processValidators(UIComponentBase.java:624) at javax.faces.component.UIForm.processValidators(UIForm.java:70) at javax.faces.component.UIComponentBase.processValidators(UIComponentBase.java:624) at javax.faces.component.UIViewRoot.processValidators(UIViewRoot.java:146) at org.apache.myfaces.lifecycle.LifecycleImpl.processValidations(LifecycleImpl.java:262) at org.apache.myfaces.lifecycle.LifecycleImpl.execute(LifecycleImpl.java:76) at javax.faces.webapp.FacesServlet.service(FacesServlet.java:137) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:252) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:173) at com.nemoves.pws.servlet.GZIPFilter.doFilter(GZIPFilter.java:35) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:202) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:173) at org.jboss.web.tomcat.filters.ReplyHeaderFilter.doFilter(ReplyHeaderFilter.java:96) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:202) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:173) at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:213) at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:178) at org.jboss.web.tomcat.security.SecurityAssociationValve.invoke(SecurityAssociationValve.java:175) at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:432) at org.jboss.web.tomcat.security.JaccContextValve.invoke(JaccContextValve.java:74) at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:126) at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:105) at org.jboss.web.tomcat.tc5.jca.CachedConnectionValve.invoke(CachedConnectionValve.java:156) at org.apache.catalina.valves.FastCommonAccessLogValve.invoke(FastCommonAccessLogValve.java:495) at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:107) at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:148) at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:869) at org.apache.coyote.http11.Http11BaseProtocol$Http11ConnectionHandler.processConnection(Http11BaseProtocol.java :664) at org.apache.tomcat.util.net.PoolTcpEndpoint.processSocket(PoolTcpEndpoint.java:527) at org.apache.tomcat.util.net.MasterSlaveWorkerThread.run(MasterSlaveWorkerThread.java:112) at java.lang.Thread.run(Thread.java:619) 12:59:26,200 FATAL [PropertySearchAction] 1224891672 - Total time to run PropertySearch.loadPage(): 51766 12:59:26,247 ERROR [JDBCExceptionReporter] Transaction is not active: tx=TransactionImpl:XidImpl[FormatId=257, GlobalId= nem-ma-nem401/1711167, BranchQual=, localId=1711167]; - nested throwable: (javax.resource.ResourceException: Transaction is not active: tx=TransactionImpl:XidImpl[FormatId=257, GlobalId=nem-ma-nem401/1711167, BranchQual=, localId=1711167]) 12:59:26,247 ERROR [JDBCExceptionReporter] Transaction is not active: tx=TransactionImpl:XidImpl[FormatId=257, GlobalId= nem-ma-nem401/1711167, BranchQual=, localId=1711167]; - nested throwable: (javax.resource.ResourceException: Transaction is not active: tx=TransactionImpl:XidImpl[FormatId=257, GlobalId=nem-ma-nem401/1711167, BranchQual=, localId=1711167]) 12:59:49,841 ERROR [STDERR] org.hibernate.exception.GenericJDBCException: Cannot open connection at org.hibernate.exception.SQLStateConverter.handledNonSpecificException(SQLStateConverter.java:103) at org.hibernate.exception.SQLStateConverter.convert(SQLStateConverter.java:91) at org.hibernate.exception.JDBCExceptionHelper.convert(JDBCExceptionHelper.java:43) at org.hibernate.exception.JDBCExceptionHelper.convert(JDBCExceptionHelper.java:29) at org.hibernate.jdbc.ConnectionManager.openConnection(ConnectionManager.java:426) at org.hibernate.jdbc.ConnectionManager.getConnection(ConnectionManager.java:144) at org.hibernate.jdbc.AbstractBatcher.prepareQueryStatement(AbstractBatcher.java:139) at org.hibernate.loader.Loader.prepareQueryStatement(Loader.java:1547) at org.hibernate.loader.Loader.doQuery(Loader.java:673) at org.hibernate.loader.Loader.doQueryAndInitializeNonLazyCollections(Loader.java:236) at org.hibernate.loader.Loader.loadCollection(Loader.java:1994) at org.hibernate.loader.collection.CollectionLoader.initialize(CollectionLoader.java:36) at org.hibernate.persister.collection.AbstractCollectionPersister.initialize(AbstractCollectionPersister.java:56 5) at org.hibernate.event.def.DefaultInitializeCollectionEventListener.onInitializeCollection(DefaultInitializeColl ectionEventListener.java:60) at org.hibernate.impl.SessionImpl.initializeCollection(SessionImpl.java:1716) at org.hibernate.collection.AbstractPersistentCollection.initialize(AbstractPersistentCollection.java:344) at org.hibernate.collection.AbstractPersistentCollection.read(AbstractPersistentCollection.java:86) at org.hibernate.collection.PersistentBag.iterator(PersistentBag.java:249) at com.nemoves.pws.bo.OfficeBO.loadManagedOffices(OfficeBO.java:435) at sun.reflect.GeneratedMethodAccessor1229.invoke(Unknown Source) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) at java.lang.reflect.Method.invoke(Method.java:597) at org.jboss.seam.util.Reflections.invoke(Reflections.java:20) at org.jboss.seam.intercept.RootInvocationContext.proceed(RootInvocationContext.java:31) at org.jboss.seam.intercept.SeamInvocationContext.proceed(SeamInvocationContext.java:57) at org.jboss.seam.interceptors.RollbackInterceptor.aroundInvoke(RollbackInterceptor.java:34) at org.jboss.seam.intercept.SeamInvocationContext.proceed(SeamInvocationContext.java:69) at org.jboss.seam.interceptors.BijectionInterceptor.aroundInvoke(BijectionInterceptor.java:47) at org.jboss.seam.intercept.SeamInvocationContext.proceed(SeamInvocationContext.java:69) at org.jboss.seam.interceptors.MethodContextInterceptor.aroundInvoke(MethodContextInterceptor.java:27) at org.jboss.seam.intercept.SeamInvocationContext.proceed(SeamInvocationContext.java:69) at org.jboss.seam.intercept.RootInterceptor.invoke(RootInterceptor.java:103) at org.jboss.seam.intercept.JavaBeanInterceptor.interceptInvocation(JavaBeanInterceptor.java:151) at org.jboss.seam.intercept.JavaBeanInterceptor.invoke(JavaBeanInterceptor.java:87) at com.nemoves.pws.bo.OfficeBO_$$_javassist_98.loadManagedOffices(OfficeBO_$$_javassist_98.java) at com.nemoves.pws.actions.officesearch.OfficeSearchAction.loadPage(OfficeSearchAction.java:155) at sun.reflect.GeneratedMethodAccessor1764.invoke(Unknown Source) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) at java.lang.reflect.Method.invoke(Method.java:597) at org.jboss.seam.util.Reflections.invoke(Reflections.java:20) at org.jboss.seam.intercept.RootInvocationContext.proceed(RootInvocationContext.java:31) at org.jboss.seam.intercept.SeamInvocationContext.proceed(SeamInvocationContext.java:57) at org.jboss.seam.interceptors.RollbackInterceptor.aroundInvoke(RollbackInterceptor.java:34) at org.jboss.seam.intercept.SeamInvocationContext.proceed(SeamInvocationContext.java:69) at org.jboss.seam.interceptors.BijectionInterceptor.aroundInvoke(BijectionInterceptor.java:47) at org.jboss.seam.intercept.SeamInvocationContext.proceed(SeamInvocationContext.java:69) at org.jboss.seam.interceptors.MethodContextInterceptor.aroundInvoke(MethodContextInterceptor.java:27) at org.jboss.seam.intercept.SeamInvocationContext.proceed(SeamInvocationContext.java:69) at org.jboss.seam.interceptors.SynchronizationInterceptor.aroundInvoke(SynchronizationInterceptor.java:31) at org.jboss.seam.intercept.SeamInvocationContext.proceed(SeamInvocationContext.java:69) at org.jboss.seam.intercept.RootInterceptor.invoke(RootInterceptor.java:103) at org.jboss.seam.intercept.JavaBeanInterceptor.interceptInvocation(JavaBeanInterceptor.java:151) at org.jboss.seam.intercept.JavaBeanInterceptor.invoke(JavaBeanInterceptor.java:87) at com.nemoves.pws.actions.officesearch.OfficeSearchAction_$$_javassist_112.loadPage(OfficeSearchAction_$$_javas sist_112.java) at com.nemoves.nexgen.utils.paginator.DefaultPaginator.<init>(DefaultPaginator.java:102) at com.nemoves.pws.actions.officesearch.ViewOfficeDetailsAction.loadOfficeAssociates(ViewOfficeDetailsAction.jav a:262) at com.nemoves.pws.actions.officesearch.ViewOfficeDetailsAction.loadOfficeDetails(ViewOfficeDetailsAction.java:2 04) at sun.reflect.GeneratedMethodAccessor1864.invoke(Unknown Source) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) at java.lang.reflect.Method.invoke(Method.java:597) at org.jboss.seam.util.Reflections.invoke(Reflections.java:20) at org.jboss.seam.intercept.RootInvocationContext.proceed(RootInvocationContext.java:31) at org.jboss.seam.intercept.SeamInvocationContext.proceed(SeamInvocationContext.java:57) at org.jboss.seam.interceptors.RollbackInterceptor.aroundInvoke(RollbackInterceptor.java:34) at org.jboss.seam.intercept.SeamInvocationContext.proceed(SeamInvocationContext.java:69) at org.jboss.seam.interceptors.BijectionInterceptor.aroundInvoke(BijectionInterceptor.java:47) at org.jboss.seam.intercept.SeamInvocationContext.proceed(SeamInvocationContext.java:69) at org.jboss.seam.interceptors.MethodContextInterceptor.aroundInvoke(MethodContextInterceptor.java:27) at org.jboss.seam.intercept.SeamInvocationContext.proceed(SeamInvocationContext.java:69) at org.jboss.seam.interceptors.SynchronizationInterceptor.aroundInvoke(SynchronizationInterceptor.java:31) at org.jboss.seam.intercept.SeamInvocationContext.proceed(SeamInvocationContext.java:69) at org.jboss.seam.intercept.RootInterceptor.invoke(RootInterceptor.java:103) at org.jboss.seam.intercept.JavaBeanInterceptor.interceptInvocation(JavaBeanInterceptor.java:151) at org.jboss.seam.intercept.JavaBeanInterceptor.invoke(JavaBeanInterceptor.java:87) at com.nemoves.pws.actions.officesearch.ViewOfficeDetailsAction_$$_javassist_128.loadOfficeDetails(ViewOfficeDet ailsAction_$$_javassist_128.java) at sun.reflect.GeneratedMethodAccessor5149.invoke(Unknown Source) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) at java.lang.reflect.Method.invoke(Method.java:597) at org.apache.myfaces.el.MethodBindingImpl.invoke(MethodBindingImpl.java:129) at org.jboss.seam.actionparam.ActionParamBindingHelper.invokeTheExpression(ActionParamBindingHelper.java:58) at org.jboss.seam.actionparam.ActionParamMethodBinding.invoke(ActionParamMethodBinding.java:75) at org.jboss.seam.core.Expressions$2.invoke(Expressions.java:148) at org.jboss.seam.pages.Page.enter(Page.java:229) at org.jboss.seam.core.Pages.enterPage(Pages.java:276) at org.jboss.seam.jsf.AbstractSeamPhaseListener.enterPage(AbstractSeamPhaseListener.java:276) at org.jboss.seam.jsf.AbstractSeamPhaseListener.beforeRender(AbstractSeamPhaseListener.java:214) at org.jboss.seam.jsf.SeamPhaseListener.beforePhase(SeamPhaseListener.java:56) at org.apache.myfaces.lifecycle.PhaseListenerManager.informPhaseListenersBefore(PhaseListenerManager.java:70) at org.apache.myfaces.lifecycle.LifecycleImpl.render(LifecycleImpl.java:373) at javax.faces.webapp.FacesServlet.service(FacesServlet.java:138) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:252) at org.apache.catalina.c 12:59:49,887 ERROR [STDERR] ore.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:173) at com.nemoves.pws.servlet.GZIPFilter.doFilter(GZIPFilter.java:31) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:202) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:173) at org.jboss.web.tomcat.filters.ReplyHeaderFilter.doFilter(ReplyHeaderFilter.java:96) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:202) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:173) at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:213) at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:178) at org.jboss.web.tomcat.security.SecurityAssociationValve.invoke(SecurityAssociationValve.java:175) at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:432) at org.jboss.web.tomcat.security.JaccContextValve.invoke(JaccContextValve.java:74) at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:126) at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:105) at org.jboss.web.tomcat.tc5.jca.CachedConnectionValve.invoke(CachedConnectionValve.java:156) at org.apache.catalina.valves.FastCommonAccessLogValve.invoke(FastCommonAccessLogValve.java:495) at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:107) at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:148) at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:869) at org.apache.coyote.http11.Http11BaseProtocol$Http11ConnectionHandler.processConnection(Http11BaseProtocol.java :664) at org.apache.tomcat.util.net.PoolTcpEndpoint.processSocket(PoolTcpEndpoint.java:527) at org.apache.tomcat.util.net.MasterSlaveWorkerThread.run(MasterSlaveWorkerThread.java:112) at java.lang.Thread.run(Thread.java:619)
Any pointers on tracking this down are appreciated. If you need to know more just ask.
Thanks!