[jboss-user] [EJB 3.0 Development] New message: "Re: Default remove timeout"

jaikiran pai do-not-reply at jboss.com
Sun Feb 28 06:15:39 EST 2010


User development,

A new message was posted in the thread "Default remove timeout":

http://community.jboss.org/message/529009#529009

Author  : jaikiran pai
Profile : http://community.jboss.org/people/jaikiran

Message:
--------------------------------------------------------------
I briefly looked at https://jira.jboss.org/jira/browse/JBAS-7759. The default remove timeout for EJB3 SFSB is 0 which means "no timeout". However, as can be seen in the exception stacktrace in the JIRA, it does appear that the bean session has been removed from the cache. After spending some time on this, i notice that this is a side-effect of passivation. Even though the remove timeout is 0, there are certain attributes on the cache (which backs the SFSB sessions) which trigger a passivation of the bean session. Upon passivation, the implementation of the cache (org.jboss.ejb3.cache.simple.SimpleStatefulCache) also ends up *removing* the session from the cache (without triggering a remove semantics on the bean instance):
 
if (now - centry.lastUsed >= sessionTimeout * 1000)
 {
    synchronized (centry)
    {                     
       if (centry.getCanPassivate())
       {
          if (!centry.getCanRemoveFromCache())
          {
             passivationQueue.add(centry);
          }
          else if (trace)
          {
             log.trace("Removing " + entry.getKey() + " from cache");
          }
       }
       else
       {
          centry.markedForPassivation = true;                              
          assert centry.isInUse() : centry + " is not in use, and thus will never be passivated";
       }
       // its ok to evict because it will be passivated
       // or we determined above that we can remove it
       it.remove();
    }
 }

 
Notice the "it.remove()" which results in removing the session from the cache.
 
So effectively, the passivation code passivate the instance and also removes it from cache.
 
Later on, when the HTTP session times out, the weld code ends up calling a cache.remove for this bean session. However, the remove() implementation of the org.jboss.ejb3.cache.simple.SimpleStatefulCache does *not* check to see if the session was passivated and hence should be activated first (This i think is a bug). It just checks whether the key is present in the cache map, and if not just throws a NoSuchEJBException:
 
public void remove(Object key)
{
  if(log.isTraceEnabled())
  {
     log.trace("Removing context " + key);
  }
  StatefulBeanContext ctx = null;
  synchronized (cacheMap)
  {
     ctx = cacheMap.get(key);
  }
// Jaikiran: I think there should first be a check to see if it 
// was passivated. If yes, then activate it and then remove it
  if(ctx == null)
     throw new NoSuchEJBException("Could not find Stateful bean: " + key);
...
 

 
Here are the logs that could obtain. At 15:55:01 the passivation starts resulting in passivation and removal from cache. At 16:24:35 (on HTTP session timeout) weld ends up with a NoSuchEJBException because it can't find the session in cache:
 
 

2010-02-28 15:55:01,777 TRACE [org.jboss.ejb3.cache.simple.SimpleStatefulCache.HistoryBean] (SFSB Passivation Thread - jboss.j2ee:ear=weld-pastecode.ear,jar=weld-pastecode.jar,name=HistoryBean,service=EJB3) Not passivating; id=3j001-68nh6t-g67ovht6-1-g67p25bl-aq only inactive 28256 ms
2010-02-28 16:00:01,823 DEBUG [org.jboss.ejb3.cache.simple.StatefulSessionFilePersistenceManager] (SFSB Passivation Thread - jboss.j2ee:ear=weld-pastecode.ear,jar=weld-pastecode.jar,name=HistoryBean,service=EJB3) Attempting to passivate; id=3j001-68nh6t-g67ovht6-1-g67p25bl-aq
2010-02-28 16:00:01,837 TRACE [org.jboss.ejb3.interceptors.metadata.EnvironmentInterceptorMetaDataBridge] (SFSB Passivation Thread - jboss.j2ee:ear=weld-pastecode.ear,jar=weld-pastecode.jar,name=HistoryBean,service=EJB3) retrieve annotation interface javax.ejb.PrePassivate on org.jboss.metadata.ejb.spec.InterceptorMetaData at c6ed6111{org.jboss.weld.integration.ejb.SessionBeanInterceptor} for postConstruct[javax.interceptor.InvocationContext] declaring=org.jboss.weld.integration.ejb.SessionBeanInterceptor
2010-02-28 16:00:01,838 TRACE [org.jboss.ejb3.interceptors.metadata.EnvironmentInterceptorMetaDataBridge] (SFSB Passivation Thread - jboss.j2ee:ear=weld-pastecode.ear,jar=weld-pastecode.jar,name=HistoryBean,service=EJB3) retrieve annotation interface javax.ejb.PrePassivate on org.jboss.metadata.ejb.spec.InterceptorMetaData at c6ed6111{org.jboss.weld.integration.ejb.SessionBeanInterceptor} for preDestroy[javax.interceptor.InvocationContext] declaring=org.jboss.weld.integration.ejb.SessionBeanInterceptor
2010-02-28 16:00:01,838 TRACE [org.jboss.ejb3.interceptors.metadata.EnvironmentInterceptorMetaDataBridge] (SFSB Passivation Thread - jboss.j2ee:ear=weld-pastecode.ear,jar=weld-pastecode.jar,name=HistoryBean,service=EJB3) retrieve annotation interface javax.ejb.PrePassivate on org.jboss.metadata.ejb.spec.InterceptorMetaData at 79183f13{org.jboss.weld.integration.ejb.interceptor.Jsr299BindingsInterceptor} for init[javax.interceptor.InvocationContext] declaring=org.jboss.weld.integration.ejb.interceptor.Jsr299BindingsInterceptor
2010-02-28 16:00:01,838 TRACE [org.jboss.ejb3.interceptors.metadata.EnvironmentInterceptorMetaDataBridge] (SFSB Passivation Thread - jboss.j2ee:ear=weld-pastecode.ear,jar=weld-pastecode.jar,name=HistoryBean,service=EJB3) retrieve annotation interface javax.ejb.PrePassivate on org.jboss.metadata.ejb.spec.InterceptorMetaData at 79183f13{org.jboss.weld.integration.ejb.interceptor.Jsr299BindingsInterceptor} for doPostConstruct[javax.interceptor.InvocationContext] declaring=org.jboss.weld.integration.ejb.interceptor.Jsr299BindingsInterceptor
2010-02-28 16:00:01,838 TRACE [org.jboss.ejb3.interceptors.metadata.EnvironmentInterceptorMetaDataBridge] (SFSB Passivation Thread - jboss.j2ee:ear=weld-pastecode.ear,jar=weld-pastecode.jar,name=HistoryBean,service=EJB3) retrieve annotation interface javax.ejb.PrePassivate on org.jboss.metadata.ejb.spec.InterceptorMetaData at 79183f13{org.jboss.weld.integration.ejb.interceptor.Jsr299BindingsInterceptor} for doPreDestroy[javax.interceptor.InvocationContext] declaring=org.jboss.weld.integration.ejb.interceptor.Jsr299BindingsInterceptor
2010-02-28 16:00:01,838 TRACE [org.jboss.ejb3.interceptors.metadata.EnvironmentInterceptorMetaDataBridge] (SFSB Passivation Thread - jboss.j2ee:ear=weld-pastecode.ear,jar=weld-pastecode.jar,name=HistoryBean,service=EJB3) retrieve annotation interface javax.ejb.PrePassivate on org.jboss.metadata.ejb.jboss.JBossSessionBean31MetaData at 785caa44{HistoryBean} for finalize[] declaring=java.lang.Object
2010-02-28 16:00:01,838 TRACE [org.jboss.ejb3.interceptors.metadata.EnvironmentInterceptorMetaDataBridge] (SFSB Passivation Thread - jboss.j2ee:ear=weld-pastecode.ear,jar=weld-pastecode.jar,name=HistoryBean,service=EJB3) retrieve annotation interface javax.ejb.PrePassivate on org.jboss.metadata.ejb.jboss.JBossSessionBean31MetaData at 785caa44{HistoryBean} for wait[] declaring=java.lang.Object
2010-02-28 16:00:01,838 TRACE [org.jboss.ejb3.interceptors.metadata.EnvironmentInterceptorMetaDataBridge] (SFSB Passivation Thread - jboss.j2ee:ear=weld-pastecode.ear,jar=weld-pastecode.jar,name=HistoryBean,service=EJB3) retrieve annotation interface javax.ejb.PrePassivate on org.jboss.metadata.ejb.jboss.JBossSessionBean31MetaData at 785caa44{HistoryBean} for registerNatives[] declaring=java.lang.Object
2010-02-28 16:00:01,838 TRACE [org.jboss.ejb3.interceptors.metadata.EnvironmentInterceptorMetaDataBridge] (SFSB Passivation Thread - jboss.j2ee:ear=weld-pastecode.ear,jar=weld-pastecode.jar,name=HistoryBean,service=EJB3) retrieve annotation interface javax.ejb.PrePassivate on org.jboss.metadata.ejb.jboss.JBossSessionBean31MetaData at 785caa44{HistoryBean} for notify[] declaring=java.lang.Object
2010-02-28 16:00:01,839 TRACE [org.jboss.ejb3.interceptors.metadata.EnvironmentInterceptorMetaDataBridge] (SFSB Passivation Thread - jboss.j2ee:ear=weld-pastecode.ear,jar=weld-pastecode.jar,name=HistoryBean,service=EJB3) retrieve annotation interface javax.ejb.PrePassivate on org.jboss.metadata.ejb.jboss.JBossSessionBean31MetaData at 785caa44{HistoryBean} for notifyAll[] declaring=java.lang.Object
2010-02-28 16:00:01,839 TRACE [org.jboss.ejb3.interceptors.metadata.EnvironmentInterceptorMetaDataBridge] (SFSB Passivation Thread - jboss.j2ee:ear=weld-pastecode.ear,jar=weld-pastecode.jar,name=HistoryBean,service=EJB3) retrieve annotation interface javax.ejb.PrePassivate on org.jboss.metadata.ejb.jboss.JBossSessionBean31MetaData at 785caa44{HistoryBean} for initialize[] declaring=org.jboss.weld.examples.pastecode.session.HistoryBean
2010-02-28 16:00:01,839 DEBUG [org.jboss.ejb3.cache.simple.StatefulSessionFilePersistenceManager] (SFSB Passivation Thread - jboss.j2ee:ear=weld-pastecode.ear,jar=weld-pastecode.jar,name=HistoryBean,service=EJB3) Saving session state to: /NotBackedUp/jpai/jboss-6.0.0-M2/server/all/tmp/sessions/HistoryBean-g67owbpa-an/3j001-68nh6t-g67ovht6-1-g67p25bl-aq.ser
2010-02-28 16:00:02,296 DEBUG [org.jboss.ejb3.cache.simple.StatefulSessionFilePersistenceManager] (SFSB Passivation Thread - jboss.j2ee:ear=weld-pastecode.ear,jar=weld-pastecode.jar,name=HistoryBean,service=EJB3) Passivation complete; id=3j001-68nh6t-g67ovht6-1-g67p25bl-aq
2010-02-28 16:24:35,829 DEBUG [org.jboss.ejb3.common.registrar.plugin.mc.Ejb3McRegistrar] (ContainerBackgroundProcessor[StandardEngine[jboss.web]]) Returning from name "EJB3EndpointResolver": org.jboss.ejb3.endpoint.deployers.DefaultEndpointResolver at 1d5f581
2010-02-28 16:24:35,830 DEBUG [org.jboss.ejb3.endpoint.deployers.DefaultEJBIdentifier] (ContainerBackgroundProcessor[StandardEngine[jboss.web]]) Container name generated for ejb = HistoryBean in unit AbstractVFSDeploymentContext at 28008583{vfszip:/NotBackedUp/jpai/jboss-6.0.0-M2/server/all/deploy/weld-pastecode.ear/weld-pastecode.jar/} is jboss.j2ee:service=EJB3,ear=weld-pastecode.ear,jar=weld-pastecode.jar,name=HistoryBean
2010-02-28 16:24:35,831 DEBUG [org.jboss.ejb3.common.registrar.plugin.mc.Ejb3McRegistrar] (ContainerBackgroundProcessor[StandardEngine[jboss.web]]) Returning from name "jboss.j2ee:ear=weld-pastecode.ear,jar=weld-pastecode.jar,name=HistoryBean,service=EJB3_endpoint": org.jboss.ejb3.endpoint.deployers.impl.EndpointImpl at 1e90cff
2010-02-28 16:24:35,832 TRACE [org.jboss.ejb3.cache.simple.SimpleStatefulCache.HistoryBean] (ContainerBackgroundProcessor[StandardEngine[jboss.web]]) Removing context 3j001-68nh6t-g67ovht6-1-g67p25bl-aq
2010-02-28 16:24:35,912 TRACE [org.jboss.cache.commands.write.RemoveNodeCommand] (ContainerBackgroundProcessor[StandardEngine[jboss.web]]) perform(null, /JSESSION/weld-pastecode_localhost/m7eBYdcFVz3nKSCxysGsqg__)
2010-02-28 16:24:35,917 WARN  [org.jboss.web.tomcat.service.session.JBossCacheManager.weld-pastecode] (ContainerBackgroundProcessor[StandardEngine[jboss.web]]) Standard expiration of session m7eBYdcFVz3nKSCxysGsqg__ failed; switching to a brute force cleanup. Problem isCould not find Stateful bean: 3j001-68nh6t-g67ovht6-1-g67p25bl-aq
2010-02-28 16:24:35,926 TRACE [org.jboss.cache.commands.write.RemoveNodeCommand] (ContainerBackgroundProcessor[StandardEngine[jboss.web]]) perform(null, /JSESSION/weld-pastecode_localhost/m7eBYdcFVz3nKSCxysGsqg__)

 

--------------------------------------------------------------

To reply to this message visit the message page: http://community.jboss.org/message/529009#529009




More information about the jboss-user mailing list