Error with nested transactions, but I'm not nesting transact
I'm getting erratic, non-repeatable exceptions involving nested transactions, apparently from within code which is not nesting transactions. This code is accessing the TreeCacheAop service. and it runs flawlessly most of the time. Even after the exceptions are caught by JBoss I can continue with the application with no apparent side effects, and the exceptions may or may not appear again for some time.
The method in which the exception is detected is updateReceivedTime(), which creates and starts a UserTransaction. It calls another method which creates no transaction, and this method calls a third method which creates no transaction. The second and third methods in the chain each access the TreeCacheAop service via the MBeanServer, invoking the exists() and getObject() methods of the TreeCacheAop service. Once a dynamic proxy for a HashMap object is retrieved from the TreeCacheAop and returned to the original method (updateReceivedTime()) it is then used to construct a new object (UserActivity) which has two Date fields which are immediately set with values. The transaction is then committed and the method returns. The UserActivity object's field values are updated in the corresponding HashMap object stored in the TreeCacheAop -- I'm not sure how JBossCache accomplishes this, but it works almost every time, except when the nested transactions are detected. To illustrate I will list the code of the three methods mentioned above. These are part of an MBean which is being accessed from my Servlets and EJBs via MBeanServer.invoke() method calls.
public synchronized void updateReceivedTime (String userId)
throws MBeanException
{
try
{
// create and begin a transaction
UserTransaction userTransaction = (UserTransaction) m_jndiContext.lookup("UserTransaction");
userTransaction.begin();
// get the UserActivity for the user
HashMap userActivityMap = getUserActivityMap(userId);
UserActivity userActivity = new UserActivity(userActivityMap);
// set the access time, received time, and session
userActivity.setLastHeartbeatTime(new Date());
userActivity.setLastReceivedTime(new Date());
// commit the transaction
userTransaction.commit();
}
catch (Exception e)
{
// log the error and throw an Exception
m_logger.error("Unable to update the user activity information for the user with ID " + userId, e);
throw new MBeanException(e, "Unable to update the user activity information for the user with ID " + userId);
}
}
private HashMap getUserActivityMap (String userId)
throws MBeanException
{
// get the corresponding fqn of the UserActivity HashMap object for the user, if one already exists
String fullyQualifiedName = getFullyQualifiedName(userId);
// if we found a fqn then a UserActivity HashMap object for the user exists
if (fullyQualifiedName != null)
{
try
{
// return the dynamic proxy for the HashMap we're using to represent the user's UserActivity object
return (HashMap) m_mbeanServer.invoke(m_cacheService,
"getObject",
new Object[] {fullyQualifiedName},
new String[] {String.class.getName()});
}
catch (Exception e)
{
// log the error and throw an Exception
m_logger.error("Unable to get the cached UserActivity HashMap object for the user with ID " + userId, e);
throw new MBeanException(e, "Unable to get the cached UserActivity HashMap object for the user with ID " + userId);
}
}
else
{
// a corresponding HashMap object wasn't found in the cache
m_logger.warn("Unable to find a UserActivity HashMap object for the user with ID " + userId);
return null;
}
}
private String getFullyQualifiedName (String userId)
throws MBeanException
{
// build fully qualified names using the node names and the user ID
String himName = NODE_HIM + "/" + userId;
String webName = NODE_WEB + "/" + userId;
try
{
// see if a UserActivity object exists for the user under the HIM node
Boolean userExists = (Boolean) m_mbeanServer.invoke(m_cacheService,
"exists",
new Object[] {himName},
new String[] {String.class.getName()});
if (userExists.booleanValue())
{
// the fully qualified name using the HIM node is correct
return himName;
}
else
{
// see if a UserActivity object exists for the user under the WEB node
userExists = (Boolean) m_mbeanServer.invoke(m_cacheService,
"exists",
new Object[] {webName},
new String[] {String.class.getName()});
if (userExists.booleanValue())
{
// the fully qualified name using the WEB node is correct
return webName;
}
else
{
// a UserActivity object doesn't yet exist for the user and hence no corresponding fully qualified name is available
return null;
}
}
}
catch (Exception e)
{
// log the error and throw a new Exception
m_logger.warn("Unable to find the fully qualified name for user with ID " + userId, e);
throw new MBeanException(e, "Unable to find the fully qualified name for user with ID " + userId);
}
}
The exceptions I am getting are listed below:
2005-03-29 17:54:40,979 ERROR [com.harborsideplus.grover.mbean.UserActivityManager] Unable to update the user activity information for the user with ID phstrife javax.transaction.NotSupportedException: Transaction already active, cannot nest transactions. at org.jboss.tm.TxManager.begin(TxManager.java:169) at org.jboss.tm.usertx.client.ServerVMClientUserTransaction.begin(ServerVMClientUserTransaction.java:110) at com.harborsideplus.grover.mbean.UserActivityManager.updateReceivedTime(UserActivityManager.java:391) at sun.reflect.GeneratedMethodAccessor85.invoke(Unknown Source) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) at java.lang.reflect.Method.invoke(Method.java:585) at org.jboss.mx.interceptor.ReflectedDispatcher.invoke(ReflectedDispatcher.java:144) at org.jboss.mx.server.Invocation.dispatch(Invocation.java:80) at org.jboss.mx.server.Invocation.invoke(Invocation.java:72) at org.jboss.mx.server.AbstractMBeanInvoker.invoke(AbstractMBeanInvoker.java:249) at org.jboss.mx.server.MBeanServerImpl.invoke(MBeanServerImpl.java:642) at com.harborsideplus.grover.servlet.GroverServlet.updateReceivedTime(GroverServlet.java:89) at com.harborsideplus.grover.servlet.GetMessagesServlet.doGet(GetMessagesServlet.java:132) at javax.servlet.http.HttpServlet.service(HttpServlet.java:697) at javax.servlet.http.HttpServlet.service(HttpServlet.java:810) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:237) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:157) at org.jboss.web.tomcat.tc5.JvmRouteFilter.doFilter(JvmRouteFilter.java:112) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:186) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:157) at org.jboss.web.tomcat.filters.ReplyHeaderFilter.doFilter(ReplyHeaderFilter.java:75) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:186) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:157) at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:214) at org.apache.catalina.core.StandardValveContext.invokeNext(StandardValveContext.java:104) at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:520) at org.apache.catalina.core.StandardContextValve.invokeInternal(StandardContextValve.java:198) at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:152) at org.apache.catalina.core.StandardValveContext.invokeNext(StandardValveContext.java:104) at org.jboss.web.tomcat.security.CustomPrincipalValve.invoke(CustomPrincipalValve.java:66) at org.apache.catalina.core.StandardValveContext.invokeNext(StandardValveContext.java:102) at org.jboss.web.tomcat.security.SecurityAssociationValve.invoke(SecurityAssociationValve.java:153) at org.apache.catalina.core.StandardValveContext.invokeNext(StandardValveContext.java:102) at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:540) at org.apache.catalina.core.StandardValveContext.invokeNext(StandardValveContext.java:102) at org.jboss.web.tomcat.security.JaccContextValve.invoke(JaccContextValve.java:54) at org.apache.catalina.core.StandardValveContext.invokeNext(StandardValveContext.java:102) at org.jboss.web.tomcat.tc5.session.ClusteredSessionValve.invoke(ClusteredSessionValve.java:80) at org.apache.catalina.core.StandardValveContext.invokeNext(StandardValveContext.java:102) at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:520) at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:137) at org.apache.catalina.core.StandardValveContext.invokeNext(StandardValveContext.java:104) at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:118) at org.apache.catalina.core.StandardValveContext.invokeNext(StandardValveContext.java:102) at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:520) at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109) at org.apache.catalina.core.StandardValveContext.invokeNext(StandardValveContext.java:104) at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:520) at org.apache.catalina.core.ContainerBase.invoke(ContainerBase.java:929) at org.apache.coyote.tomcat5.CoyoteAdapter.service(CoyoteAdapter.java:160) at org.apache.jk.server.JkCoyoteHandler.invoke(JkCoyoteHandler.java:300) at org.apache.jk.common.HandlerRequest.invoke(HandlerRequest.java:374) at org.apache.jk.common.ChannelSocket.invoke(ChannelSocket.java:743) at org.apache.jk.common.ChannelSocket.processConnection(ChannelSocket.java:675) at org.apache.jk.common.SocketConnection.runIt(ChannelSocket.java:866) at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.java:683) at java.lang.Thread.run(Thread.java:595) 2005-03-29 17:54:40,982 ERROR [com.harborsideplus.grover.servlet.GroverServlet] Unable to update the user activity information for the user with ID phstrife javax.management.MBeanException at org.jboss.mx.interceptor.ReflectedDispatcher.handleInvocationExceptions(ReflectedDispatcher.java:169) at org.jboss.mx.interceptor.ReflectedDispatcher.invoke(ReflectedDispatcher.java:152) at org.jboss.mx.server.Invocation.dispatch(Invocation.java:80) at org.jboss.mx.server.Invocation.invoke(Invocation.java:72) at org.jboss.mx.server.AbstractMBeanInvoker.invoke(AbstractMBeanInvoker.java:249) at org.jboss.mx.server.MBeanServerImpl.invoke(MBeanServerImpl.java:642) at com.harborsideplus.grover.servlet.GroverServlet.updateReceivedTime(GroverServlet.java:89) at com.harborsideplus.grover.servlet.GetMessagesServlet.doGet(GetMessagesServlet.java:132) at javax.servlet.http.HttpServlet.service(HttpServlet.java:697) at javax.servlet.http.HttpServlet.service(HttpServlet.java:810) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:237) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:157) at org.jboss.web.tomcat.tc5.JvmRouteFilter.doFilter(JvmRouteFilter.java:112) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:186) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:157) at org.jboss.web.tomcat.filters.ReplyHeaderFilter.doFilter(ReplyHeaderFilter.java:75) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:186) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:157) at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:214) at org.apache.catalina.core.StandardValveContext.invokeNext(StandardValveContext.java:104) at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:520) at org.apache.catalina.core.StandardContextValve.invokeInternal(StandardContextValve.java:198) at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:152) at org.apache.catalina.core.StandardValveContext.invokeNext(StandardValveContext.java:104) at org.jboss.web.tomcat.security.CustomPrincipalValve.invoke(CustomPrincipalValve.java:66) at org.apache.catalina.core.StandardValveContext.invokeNext(StandardValveContext.java:102) at org.jboss.web.tomcat.security.SecurityAssociationValve.invoke(SecurityAssociationValve.java:153) at org.apache.catalina.core.StandardValveContext.invokeNext(StandardValveContext.java:102) at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:540) at org.apache.catalina.core.StandardValveContext.invokeNext(StandardValveContext.java:102) at org.jboss.web.tomcat.security.JaccContextValve.invoke(JaccContextValve.java:54) at org.apache.catalina.core.StandardValveContext.invokeNext(StandardValveContext.java:102) at org.jboss.web.tomcat.tc5.session.ClusteredSessionValve.invoke(ClusteredSessionValve.java:80) at org.apache.catalina.core.StandardValveContext.invokeNext(StandardValveContext.java:102) at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:520) at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:137) at org.apache.catalina.core.StandardValveContext.invokeNext(StandardValveContext.java:104) at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:118) at org.apache.catalina.core.StandardValveContext.invokeNext(StandardValveContext.java:102) at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:520) at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109) at org.apache.catalina.core.StandardValveContext.invokeNext(StandardValveContext.java:104) at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:520) at org.apache.catalina.core.ContainerBase.invoke(ContainerBase.java:929) at org.apache.coyote.tomcat5.CoyoteAdapter.service(CoyoteAdapter.java:160) at org.apache.jk.server.JkCoyoteHandler.invoke(JkCoyoteHandler.java:300) at org.apache.jk.common.HandlerRequest.invoke(HandlerRequest.java:374) at org.apache.jk.common.ChannelSocket.invoke(ChannelSocket.java:743) at org.apache.jk.common.ChannelSocket.processConnection(ChannelSocket.java:675) at org.apache.jk.common.SocketConnection.runIt(ChannelSocket.java:866) at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.java:683) at java.lang.Thread.run(Thread.java:595) Caused by: javax.management.MBeanException: Unable to update the user activity information for the user with ID phstrife at com.harborsideplus.grover.mbean.UserActivityManager.updateReceivedTime(UserActivityManager.java:408) at sun.reflect.GeneratedMethodAccessor85.invoke(Unknown Source) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) at java.lang.reflect.Method.invoke(Method.java:585) at org.jboss.mx.interceptor.ReflectedDispatcher.invoke(ReflectedDispatcher.java:144) ... 50 more Caused by: javax.transaction.NotSupportedException: Transaction already active, cannot nest transactions. at org.jboss.tm.TxManager.begin(TxManager.java:169) at org.jboss.tm.usertx.client.ServerVMClientUserTransaction.begin(ServerVMClientUserTransaction.java:110) at com.harborsideplus.grover.mbean.UserActivityManager.updateReceivedTime(UserActivityManager.java:391) ... 54 more 2005-03-29 17:54:41,021 ERROR [org.jboss.web.localhost.Engine] StandardWrapperValve[GetMessagesServlet]: Servlet.service() for servlet GetMessagesServlet threw exception javax.management.MBeanException at org.jboss.mx.interceptor.ReflectedDispatcher.handleInvocationExceptions(ReflectedDispatcher.java:169) at org.jboss.mx.interceptor.ReflectedDispatcher.invoke(ReflectedDispatcher.java:152) at org.jboss.mx.server.Invocation.dispatch(Invocation.java:80) at org.jboss.mx.server.Invocation.invoke(Invocation.java:72) at org.jboss.mx.server.AbstractMBeanInvoker.invoke(AbstractMBeanInvoker.java:249) at org.jboss.mx.server.MBeanServerImpl.invoke(MBeanServerImpl.java:642) at com.harborsideplus.grover.servlet.GroverServlet.updateReceivedTime(GroverServlet.java:89) at com.harborsideplus.grover.servlet.GetMessagesServlet.doGet(GetMessagesServlet.java:132) at javax.servlet.http.HttpServlet.service(HttpServlet.java:697) at javax.servlet.http.HttpServlet.service(HttpServlet.java:810) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:237) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:157) at org.jboss.web.tomcat.tc5.JvmRouteFilter.doFilter(JvmRouteFilter.java:112) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:186) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:157) at org.jboss.web.tomcat.filters.ReplyHeaderFilter.doFilter(ReplyHeaderFilter.java:75) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:186) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:157) at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:214) at org.apache.catalina.core.StandardValveContext.invokeNext(StandardValveContext.java:104) at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:520) at org.apache.catalina.core.StandardContextValve.invokeInternal(StandardContextValve.java:198) at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:152) at org.apache.catalina.core.StandardValveContext.invokeNext(StandardValveContext.java:104) at org.jboss.web.tomcat.security.CustomPrincipalValve.invoke(CustomPrincipalValve.java:66) at org.apache.catalina.core.StandardValveContext.invokeNext(StandardValveContext.java:102) at org.jboss.web.tomcat.security.SecurityAssociationValve.invoke(SecurityAssociationValve.java:153) at org.apache.catalina.core.StandardValveContext.invokeNext(StandardValveContext.java:102) at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:540) at org.apache.catalina.core.StandardValveContext.invokeNext(StandardValveContext.java:102) at org.jboss.web.tomcat.security.JaccContextValve.invoke(JaccContextValve.java:54) at org.apache.catalina.core.StandardValveContext.invokeNext(StandardValveContext.java:102) at org.jboss.web.tomcat.tc5.session.ClusteredSessionValve.invoke(ClusteredSessionValve.java:80) at org.apache.catalina.core.StandardValveContext.invokeNext(StandardValveContext.java:102) at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:520) at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:137) at org.apache.catalina.core.StandardValveContext.invokeNext(StandardValveContext.java:104) at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:118) at org.apache.catalina.core.StandardValveContext.invokeNext(StandardValveContext.java:102) at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:520) at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109) at org.apache.catalina.core.StandardValveContext.invokeNext(StandardValveContext.java:104) at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:520) at org.apache.catalina.core.ContainerBase.invoke(ContainerBase.java:929) at org.apache.coyote.tomcat5.CoyoteAdapter.service(CoyoteAdapter.java:160) at org.apache.jk.server.JkCoyoteHandler.invoke(JkCoyoteHandler.java:300) at org.apache.jk.common.HandlerRequest.invoke(HandlerRequest.java:374) at org.apache.jk.common.ChannelSocket.invoke(ChannelSocket.java:743) at org.apache.jk.common.ChannelSocket.processConnection(ChannelSocket.java:675) at org.apache.jk.common.SocketConnection.runIt(ChannelSocket.java:866) at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.java:683) at java.lang.Thread.run(Thread.java:595) Caused by: javax.management.MBeanException: Unable to update the user activity information for the user with ID phstrife at com.harborsideplus.grover.mbean.UserActivityManager.updateReceivedTime(UserActivityManager.java:408) at sun.reflect.GeneratedMethodAccessor85.invoke(Unknown Source) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) at java.lang.reflect.Method.invoke(Method.java:585) at org.jboss.mx.interceptor.ReflectedDispatcher.invoke(ReflectedDispatcher.java:144) ... 50 more Caused by: javax.transaction.NotSupportedException: Transaction already active, cannot nest transactions. at org.jboss.tm.TxManager.begin(TxManager.java:169) at org.jboss.tm.usertx.client.ServerVMClientUserTransaction.begin(ServerVMClientUserTransaction.java:110) at com.harborsideplus.grover.mbean.UserActivityManager.updateReceivedTime(UserActivityManager.java:391) ... 54 more
I will really appreciate any insight into this problem, as I am stumped.
--James
