Why when I convert managed bean to SFSB do I get TwoPhaseCoordinator.afterCompletion - returned failure for SynchronizationImple
My @SessionScoped WorkflowManager managed bean was able to reset state when session timed out, causing Welcome splash screen to be displayed. After adding @Stateful to the WorkflowManager the Welcome screen is not consistently shown and it seems that session is actually not timing out properly in a consistent fashion from looking at server.log. When the browser makes a request after session timeout the ViewExpiredExceptionHandler is supposed to redirect to the splash screen. Instead, what appears is the following stack trace and warning:
11:56:31,705 WARN [com.arjuna.ats.jta] (http--127.0.0.1-8443-7) ARJUNA016029: SynchronizationImple.afterCompletion - failed for org.jboss.as.ejb3.component.stateful.StatefulSessionSynchronizationInterceptor$StatefulSessionSynchronization@b344a2 with exception: java.lang.IllegalStateException: JBAS014531: Cache entry {[71, -15, 7, -59, -96, 28, 64, 76, -124, 16, -84, 49, 117, 10, -19, 21]} is not in use
at org.jboss.as.ejb3.cache.impl.backing.NonPassivatingBackingCacheImpl.release(NonPassivatingBackingCacheImpl.java:134) [jboss-as-ejb3-7.1.1.Final.jar:7.1.1.Final]
at org.jboss.as.ejb3.cache.impl.backing.NonPassivatingBackingCacheImpl.release(NonPassivatingBackingCacheImpl.java:56) [jboss-as-ejb3-7.1.1.Final.jar:7.1.1.Final]
at org.jboss.as.ejb3.cache.spi.impl.AbstractCache.release(AbstractCache.java:76) [jboss-as-ejb3-7.1.1.Final.jar:7.1.1.Final]
at org.jboss.as.ejb3.cache.spi.impl.AbstractCache.release(AbstractCache.java:39) [jboss-as-ejb3-7.1.1.Final.jar:7.1.1.Final]
at org.jboss.as.ejb3.component.stateful.StatefulSessionSynchronizationInterceptor.releaseInstance(StatefulSessionSynchronizationInterceptor.java:197) [jboss-as-ejb3-7.1.1.Final.jar:7.1.1.Final]
at org.jboss.as.ejb3.component.stateful.StatefulSessionSynchronizationInterceptor.access$200(StatefulSessionSynchronizationInterceptor.java:50) [jboss-as-ejb3-7.1.1.Final.jar:7.1.1.Final]
at org.jboss.as.ejb3.component.stateful.StatefulSessionSynchronizationInterceptor$StatefulSessionSynchronization.afterCompletion(StatefulSessionSynchronizationInterceptor.java:271) [jboss-as-ejb3-7.1.1.Final.jar:7.1.1.Final]
at com.arjuna.ats.internal.jta.resources.arjunacore.SynchronizationImple.afterCompletion(SynchronizationImple.java:96)
at com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.afterCompletion(TwoPhaseCoordinator.java:402)
at com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.end(TwoPhaseCoordinator.java:103)
at com.arjuna.ats.arjuna.AtomicAction.commit(AtomicAction.java:164)
at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.commitAndDisassociate(TransactionImple.java:1165)
at com.arjuna.ats.internal.jta.transaction.arjunacore.BaseTransaction.commit(BaseTransaction.java:117)
at com.arjuna.ats.jbossatx.BaseTransactionManagerDelegate.commit(BaseTransactionManagerDelegate.java:75)
at org.jboss.as.ejb3.tx.CMTTxInterceptor.endTransaction(CMTTxInterceptor.java:92) [jboss-as-ejb3-7.1.1.Final.jar:7.1.1.Final]
at org.jboss.as.ejb3.tx.CMTTxInterceptor.invokeInOurTx(CMTTxInterceptor.java:232) [jboss-as-ejb3-7.1.1.Final.jar:7.1.1.Final]
at org.jboss.as.ejb3.tx.CMTTxInterceptor.required(CMTTxInterceptor.java:304) [jboss-as-ejb3-7.1.1.Final.jar:7.1.1.Final]
at org.jboss.as.ejb3.tx.CMTTxInterceptor.processInvocation(CMTTxInterceptor.java:190) [jboss-as-ejb3-7.1.1.Final.jar:7.1.1.Final]
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.1.Final.jar:1.1.1.Final]
at org.jboss.as.ejb3.component.interceptors.CurrentInvocationContextInterceptor.processInvocation(CurrentInvocationContextInterceptor.java:41) [jboss-as-ejb3-7.1.1.Final.jar:7.1.1.Final]
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.1.Final.jar:1.1.1.Final]
at org.jboss.as.ejb3.component.interceptors.LoggingInterceptor.processInvocation(LoggingInterceptor.java:59) [jboss-as-ejb3-7.1.1.Final.jar:7.1.1.Final]
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.1.Final.jar:1.1.1.Final]
at org.jboss.as.ee.component.NamespaceContextInterceptor.processInvocation(NamespaceContextInterceptor.java:50) [jboss-as-ee-7.1.1.Final.jar:7.1.1.Final]
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.1.Final.jar:1.1.1.Final]
at org.jboss.as.ee.component.TCCLInterceptor.processInvocation(TCCLInterceptor.java:45) [jboss-as-ee-7.1.1.Final.jar:7.1.1.Final]
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.1.Final.jar:1.1.1.Final]
at org.jboss.invocation.ChainedInterceptor.processInvocation(ChainedInterceptor.java:61) [jboss-invocation-1.1.1.Final.jar:1.1.1.Final]
at org.jboss.as.ee.component.ViewService$View.invoke(ViewService.java:165) [jboss-as-ee-7.1.1.Final.jar:7.1.1.Final]
at org.jboss.as.ee.component.ViewDescription$1.processInvocation(ViewDescription.java:173) [jboss-as-ee-7.1.1.Final.jar:7.1.1.Final]
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.1.Final.jar:1.1.1.Final]
at org.jboss.as.ejb3.component.stateful.StatefulComponentIdInterceptor.processInvocation(StatefulComponentIdInterceptor.java:52) [jboss-as-ejb3-7.1.1.Final.jar:7.1.1.Final]
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.1.Final.jar:1.1.1.Final]
at org.jboss.invocation.ChainedInterceptor.processInvocation(ChainedInterceptor.java:61) [jboss-invocation-1.1.1.Final.jar:1.1.1.Final]
at org.jboss.as.ee.component.ProxyInvocationHandler.invoke(ProxyInvocationHandler.java:72) [jboss-as-ee-7.1.1.Final.jar:7.1.1.Final]
at com.patrac.controller.statemachine.WorkflowManager$$$view7.getCurrentWorkflow(Unknown Source) [Patrac-ejb.jar:]
at sun.reflect.GeneratedMethodAccessor36.invoke(Unknown Source) [:1.7.0_03]
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) [rt.jar:1.7.0_03]
at java.lang.reflect.Method.invoke(Method.java:601) [rt.jar:1.7.0_03]
at org.jboss.weld.util.reflection.SecureReflections$13.work(SecureReflections.java:264) [weld-core-1.1.5.AS71.Final.jar:2012-02-10 15:31]
at org.jboss.weld.util.reflection.SecureReflectionAccess.run(SecureReflectionAccess.java:52) [weld-core-1.1.5.AS71.Final.jar:2012-02-10 15:31]
at org.jboss.weld.util.reflection.SecureReflectionAccess.runAsInvocation(SecureReflectionAccess.java:137) [weld-core-1.1.5.AS71.Final.jar:2012-02-10 15:31]
at org.jboss.weld.util.reflection.SecureReflections.invoke(SecureReflections.java:260) [weld-core-1.1.5.AS71.Final.jar:2012-02-10 15:31]
at org.jboss.weld.bean.proxy.EnterpriseBeanProxyMethodHandler.invoke(EnterpriseBeanProxyMethodHandler.java:111) [weld-core-1.1.5.AS71.Final.jar:2012-02-10 15:31]
at org.jboss.weld.bean.proxy.EnterpriseTargetBeanInstance.invoke(EnterpriseTargetBeanInstance.java:56) [weld-core-1.1.5.AS71.Final.jar:2012-02-10 15:31]
at org.jboss.weld.bean.proxy.ProxyMethodHandler.invoke(ProxyMethodHandler.java:105) [weld-core-1.1.5.AS71.Final.jar:2012-02-10 15:31]
at com.patrac.controller.statemachine.WorkflowManager$Proxy$_$$_Weld$Proxy$.getCurrentWorkflow(WorkflowManager$Proxy$_$$_Weld$Proxy$.java) [Patrac-ejb.jar:]
at com.patrac.controller.statemachine.WorkflowManager$Proxy$_$$_WeldClientProxy.getCurrentWorkflow(WorkflowManager$Proxy$_$$_WeldClientProxy.java) [Patrac-ejb.jar:]
at sun.reflect.GeneratedMethodAccessor41.invoke(Unknown Source) [:1.7.0_03]
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) [rt.jar:1.7.0_03]
at java.lang.reflect.Method.invoke(Method.java:601) [rt.jar:1.7.0_03]
at javax.el.BeanELResolver.getValue(BeanELResolver.java:302) [jboss-el-api_2.2_spec-1.0.0.Final.jar:1.0.0.Final]
at com.sun.faces.el.DemuxCompositeELResolver._getValue(DemuxCompositeELResolver.java:176) [jsf-impl-2.1.7-jbossorg-2.jar:]
at com.sun.faces.el.DemuxCompositeELResolver.getValue(DemuxCompositeELResolver.java:203) [jsf-impl-2.1.7-jbossorg-2.jar:]
at org.apache.el.parser.AstValue.getValue(AstValue.java:169) [jbossweb-7.0.13.Final.jar:]
at org.apache.el.ValueExpressionImpl.getValue(ValueExpressionImpl.java:189) [jbossweb-7.0.13.Final.jar:]
at org.jboss.weld.el.WeldValueExpression.getValue(WeldValueExpression.java:50) [weld-core-1.1.5.AS71.Final.jar:2012-02-10 15:31]
at com.sun.faces.facelets.el.TagValueExpression.getValue(TagValueExpression.java:109) [jsf-impl-2.1.7-jbossorg-2.jar:]
at com.sun.faces.facelets.tag.TagAttributeImpl.getObject(TagAttributeImpl.java:329) [jsf-impl-2.1.7-jbossorg-2.jar:]
at com.sun.faces.facelets.tag.TagAttributeImpl.getValue(TagAttributeImpl.java:295) [jsf-impl-2.1.7-jbossorg-2.jar:]
at com.sun.faces.facelets.tag.ui.IncludeHandler.apply(IncludeHandler.java:134) [jsf-impl-2.1.7-jbossorg-2.jar:]
at com.sun.faces.facelets.tag.ui.DefineHandler.applyDefinition(DefineHandler.java:107) [jsf-impl-2.1.7-jbossorg-2.jar:]
at com.sun.faces.facelets.tag.ui.CompositionHandler.apply(CompositionHandler.java:178) [jsf-impl-2.1.7-jbossorg-2.jar:]
at com.sun.faces.facelets.impl.DefaultFaceletContext$TemplateManager.apply(DefaultFaceletContext.java:395) [jsf-impl-2.1.7-jbossorg-2.jar:]
at com.sun.faces.facelets.impl.DefaultFaceletContext.includeDefinition(DefaultFaceletContext.java:366) [jsf-impl-2.1.7-jbossorg-2.jar:]
at com.sun.faces.facelets.tag.ui.InsertHandler.apply(InsertHandler.java:112) [jsf-impl-2.1.7-jbossorg-2.jar:]
at javax.faces.view.facelets.CompositeFaceletHandler.apply(CompositeFaceletHandler.java:98) [jboss-jsf-api_2.1_spec-2.0.1.Final.jar:2.0.1.Final]
at com.sun.faces.facelets.tag.jsf.core.ViewHandler.apply(ViewHandler.java:182) [jsf-impl-2.1.7-jbossorg-2.jar:]
at javax.faces.view.facelets.CompositeFaceletHandler.apply(CompositeFaceletHandler.java:98) [jboss-jsf-api_2.1_spec-2.0.1.Final.jar:2.0.1.Final]
at javax.faces.view.facelets.DelegatingMetaTagHandler.applyNextHandler(DelegatingMetaTagHandler.java:137) [jboss-jsf-api_2.1_spec-2.0.1.Final.jar:2.0.1.Final]
at org.richfaces.view.facelets.html.BehaviorsAddingComponentHandlerWrapper.applyNextHandler(BehaviorsAddingComponentHandlerWrapper.java:53) [richfaces-components-ui-4.2.2.Final.jar:4.2.2.Final]
at com.sun.faces.facelets.tag.jsf.ComponentTagHandlerDelegateImpl.apply(ComponentTagHandlerDelegateImpl.java:195) [jsf-impl-2.1.7-jbossorg-2.jar:]
at javax.faces.view.facelets.DelegatingMetaTagHandler.apply(DelegatingMetaTagHandler.java:120) [jboss-jsf-api_2.1_spec-2.0.1.Final.jar:2.0.1.Final]
at com.sun.faces.facelets.tag.jstl.core.ChooseOtherwiseHandler.apply(ChooseOtherwiseHandler.java:79) [jsf-impl-2.1.7-jbossorg-2.jar:]
at com.sun.faces.facelets.tag.jstl.core.ChooseHandler.apply(ChooseHandler.java:110) [jsf-impl-2.1.7-jbossorg-2.jar:]
at javax.faces.view.facelets.CompositeFaceletHandler.apply(CompositeFaceletHandler.java:98) [jboss-jsf-api_2.1_spec-2.0.1.Final.jar:2.0.1.Final]
at com.sun.faces.facelets.compiler.NamespaceHandler.apply(NamespaceHandler.java:93) [jsf-impl-2.1.7-jbossorg-2.jar:]
at javax.faces.view.facelets.CompositeFaceletHandler.apply(CompositeFaceletHandler.java:98) [jboss-jsf-api_2.1_spec-2.0.1.Final.jar:2.0.1.Final]
at com.sun.faces.facelets.compiler.EncodingHandler.apply(EncodingHandler.java:86) [jsf-impl-2.1.7-jbossorg-2.jar:]
at com.sun.faces.facelets.impl.DefaultFacelet.include(DefaultFacelet.java:308) [jsf-impl-2.1.7-jbossorg-2.jar:]
at com.sun.faces.facelets.impl.DefaultFacelet.include(DefaultFacelet.java:367) [jsf-impl-2.1.7-jbossorg-2.jar:]
at com.sun.faces.facelets.impl.DefaultFacelet.include(DefaultFacelet.java:346) [jsf-impl-2.1.7-jbossorg-2.jar:]
at com.sun.faces.facelets.impl.DefaultFaceletContext.includeFacelet(DefaultFaceletContext.java:199) [jsf-impl-2.1.7-jbossorg-2.jar:]
at com.sun.faces.facelets.tag.ui.CompositionHandler.apply(CompositionHandler.java:155) [jsf-impl-2.1.7-jbossorg-2.jar:]
at com.sun.faces.facelets.compiler.NamespaceHandler.apply(NamespaceHandler.java:93) [jsf-impl-2.1.7-jbossorg-2.jar:]
at com.sun.faces.facelets.compiler.EncodingHandler.apply(EncodingHandler.java:86) [jsf-impl-2.1.7-jbossorg-2.jar:]
at com.sun.faces.facelets.impl.DefaultFacelet.apply(DefaultFacelet.java:152) [jsf-impl-2.1.7-jbossorg-2.jar:]
at com.sun.faces.application.view.FaceletViewHandlingStrategy.buildView(FaceletViewHandlingStrategy.java:774) [jsf-impl-2.1.7-jbossorg-2.jar:]
at com.sun.faces.application.view.StateManagementStrategyImpl.restoreView(StateManagementStrategyImpl.java:220) [jsf-impl-2.1.7-jbossorg-2.jar:]
at com.sun.faces.application.StateManagerImpl.restoreView(StateManagerImpl.java:188) [jsf-impl-2.1.7-jbossorg-2.jar:]
at com.sun.faces.application.view.ViewHandlingStrategy.restoreView(ViewHandlingStrategy.java:123) [jsf-impl-2.1.7-jbossorg-2.jar:]
at com.sun.faces.application.view.FaceletViewHandlingStrategy.restoreView(FaceletViewHandlingStrategy.java:453) [jsf-impl-2.1.7-jbossorg-2.jar:]
at com.sun.faces.application.view.MultiViewHandler.restoreView(MultiViewHandler.java:142) [jsf-impl-2.1.7-jbossorg-2.jar:]
at javax.faces.application.ViewHandlerWrapper.restoreView(ViewHandlerWrapper.java:303) [jboss-jsf-api_2.1_spec-2.0.1.Final.jar:2.0.1.Final]
at javax.faces.application.ViewHandlerWrapper.restoreView(ViewHandlerWrapper.java:303) [jboss-jsf-api_2.1_spec-2.0.1.Final.jar:2.0.1.Final]
at com.sun.faces.lifecycle.RestoreViewPhase.execute(RestoreViewPhase.java:192) [jsf-impl-2.1.7-jbossorg-2.jar:]
at com.sun.faces.lifecycle.Phase.doPhase(Phase.java:101) [jsf-impl-2.1.7-jbossorg-2.jar:]
at com.sun.faces.lifecycle.RestoreViewPhase.doPhase(RestoreViewPhase.java:116) [jsf-impl-2.1.7-jbossorg-2.jar:]
at com.sun.faces.lifecycle.LifecycleImpl.execute(LifecycleImpl.java:118) [jsf-impl-2.1.7-jbossorg-2.jar:]
at javax.faces.webapp.FacesServlet.service(FacesServlet.java:593) [jboss-jsf-api_2.1_spec-2.0.1.Final.jar:2.0.1.Final]
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:329) [jbossweb-7.0.13.Final.jar:]
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:248) [jbossweb-7.0.13.Final.jar:]
at org.jboss.weld.servlet.ConversationPropagationFilter.doFilter(ConversationPropagationFilter.java:62) [weld-core-1.1.5.AS71.Final.jar:2012-02-10 15:31]
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:280) [jbossweb-7.0.13.Final.jar:]
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:248) [jbossweb-7.0.13.Final.jar:]
at com.patrac.filter.NoCacheFilter.doFilter(NoCacheFilter.java:46) [classes:]
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:280) [jbossweb-7.0.13.Final.jar:]
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:248) [jbossweb-7.0.13.Final.jar:]
at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:275) [jbossweb-7.0.13.Final.jar:]
at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:161) [jbossweb-7.0.13.Final.jar:]
at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:489) [jbossweb-7.0.13.Final.jar:]
at org.jboss.as.jpa.interceptor.WebNonTxEmCloserValve.invoke(WebNonTxEmCloserValve.java:50) [jboss-as-jpa-7.1.1.Final.jar:7.1.1.Final]
at org.jboss.as.web.security.SecurityContextAssociationValve.invoke(SecurityContextAssociationValve.java:153) [jboss-as-web-7.1.1.Final.jar:7.1.1.Final]
at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:155) [jbossweb-7.0.13.Final.jar:]
at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:102) [jbossweb-7.0.13.Final.jar:]
at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109) [jbossweb-7.0.13.Final.jar:]
at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:368) [jbossweb-7.0.13.Final.jar:]
at org.apache.coyote.http11.Http11AprProcessor.process(Http11AprProcessor.java:897) [jbossweb-7.0.13.Final.jar:]
at org.apache.coyote.http11.Http11AprProtocol$Http11ConnectionHandler.process(Http11AprProtocol.java:626) [jbossweb-7.0.13.Final.jar:]
at org.apache.tomcat.util.net.AprEndpoint$Worker.run(AprEndpoint.java:2039) [jbossweb-7.0.13.Final.jar:]
at java.lang.Thread.run(Thread.java:722) [rt.jar:1.7.0_03]
11:56:31,845 WARN [com.arjuna.ats.arjuna] (http--127.0.0.1-8443-7) ARJUNA012127: TwoPhaseCoordinator.afterCompletion - returned failure for SynchronizationImple< 0:ffffc0a80164:a75277:502fb8ae:9f6, org.jboss.as.ejb3.component.stateful.StatefulSessionSynchronizationInterceptor$StatefulSessionSynchronization@b344a2 >
11:56:31,855 WARNING [com.patrac.controller.exceptionhandler.ViewExpiredExceptionHandler] (http--127.0.0.1-8443-7) Attempt to access an expired view: /index.xhtml from remote host: 127.0.0.1
After the session times out the WorkflowManager should be destroyed and the next request from the client should cause a new WorkflowManager to be created. This is the way it worked just fine when WorkflowManager was a managed bean. Why, then, is JBoss trying to restore the previously destroyed WorkflowManager? What can I do to resolve this?