[jbosscache-dev] Cache bean deployment via MC failing when TRACE enabled on org.jboss.kernel

[Galder Zamarreno]

Galder Zamarreno wrote:
> Hi,
> 
> Bear with me on this one, it's a bit long :)
> 
> I've been running some tests creating Cache instances via MC and I've 
> noticed that when TRACE logging is enabled on org.jboss.kernel, my Cache 
> beans are not deployed whereas when org.jboss.kernel is set to DEBUG or 
> higher, Cache beans deploy fine.
> 
> The error I'm getting is the following:
> 
> 2009-03-03 21:40:51,505 ERROR [AbstractKernelController] (main) Error 
> installing to Instantiated: name=CacheClusterA1 state=Described
> java.lang.UnsupportedOperationException: Not supported in UnversionedNode
>     at 
> org.jboss.cache.AbstractNode.getChildrenDirect(AbstractNode.java:277)
>     at 
> org.jboss.cache.mvcc.NodeReference.getChildrenDirect(NodeReference.java:272) 
> 
>     at 
> org.jboss.cache.invocation.NodeInvocationDelegate.getChildrenDirect(NodeInvocationDelegate.java:163) 
> 
>     at 
> org.jboss.cache.DataContainerImpl.numNodes(DataContainerImpl.java:461)
>     at 
> org.jboss.cache.DataContainerImpl.getNumberOfNodes(DataContainerImpl.java:438) 
> 
>     at 
> org.jboss.cache.DataContainerImpl.toString(DataContainerImpl.java:394)
>     at 
> org.jboss.cache.DataContainerImpl.toString(DataContainerImpl.java:372)
>     at 
> org.jboss.cache.invocation.CacheInvocationDelegate.toString(CacheInvocationDelegate.java:144) 
> 
>     at java.lang.String.valueOf(String.java:2615)
>     at 
> org.jboss.util.JBossStringBuilder.append(JBossStringBuilder.java:114)
>     at 
> org.jboss.dependency.plugins.AbstractControllerContext.toString(AbstractControllerContext.java:362) 
> 
> 
> Looks like in TRACE mode, MC is trying to print the Cache when this is 
> not fully started.
> 
> To try to understand this, let's look at what DataContainerImpl logs 
> when org.jboss.kernel is set to DEBUG:
> 
> log4j-jboss-kerneldebug.log:2894:2009-03-03 21:40:24,249 2198  TRACE 
> [org.jboss.cache.DataContainerImpl] (main:) Starting data container. 
> Using MVCC? false
> log4j-jboss-kerneldebug.log:2895:2009-03-03 21:40:24,274 2223  TRACE 
> [org.jboss.cache.DataContainerImpl] (main:) Setting root node to an 
> instance of class org.jboss.cache.mvcc.NodeReference
> ...
> log4j-jboss-kerneldebug.log:3038:2009-03-03 21:40:24,336 2285  TRACE 
> [org.jboss.cache.DataContainerImpl] (main:) Starting data container. 
> Using MVCC? true
> log4j-jboss-kerneldebug.log:3039:2009-03-03 21:40:24,338 2287  DEBUG 
> [org.jboss.cache.DataContainerImpl] (main:) Setting rootInternal to 
> NodeReference{delegate=UnversionedNode[ /]}
> 
> After MVCC has been set to true, DataContainerImpl.getNumberOfNodes() is 
> able to get the number of nodes successfully:
> 
>       if (!usingMvcc) return numNodes(root) - 1;
>       return numNodesMvcc(rootInternal) - 1;
> 
> However, if in between the two "Starting data container" messages, 
> someone (i.e. MC), tries to get the number of nodes (via toString), then 
> Cache tries to get number of nodes of a MVCC node as a non MVCC node 
> failing with the exception above. This is exactly what happens when you 
> enable TRACE on MC kernel.
> 
> numNodesMvcc() calls getChildren(). numNodes calls getChildrenDirect().
> 
> With this TRACE enabled, log only show the first two lines:
> 
> log4j-jboss-kerneltrace.log:6731:2009-03-03 21:40:51,468 2817  TRACE 
> [org.jboss.cache.DataContainerImpl] (main:) Starting data container. 
> Using MVCC? false
> log4j-jboss-kerneltrace.log:6732:2009-03-03 21:40:51,475 2824  TRACE 
> [org.jboss.cache.DataContainerImpl] (main:) Setting root node to an 
> instance of class org.jboss.cache.mvcc.NodeReference
> 
> So, how do we solve this?
> 
> I'm not sure I understand why DataContainerImpl.createRootNode() is 
> called twice. The very first call, which seems to come from 
> DataContainerImpl.injectDependencies() method (annotated with @Inject) 
> looks suspicious. Why does it look suspicious? Because calls like this 
> expect a config to be set. And when they're called initially from 
> @Inject, the config object is not still set (when the call comes as part 
> of the start operation, config is indeed set)
> 
> usingMvcc = config != null && config.getNodeLockingScheme() == 
> NodeLockingScheme.MVCC;
> 
> And this returning false, when in fact the config is set to MVCC is what 
> results of number of nodes being calculated incorrectly.
> 
> Not sure on how to fix this though.
> 
> Thoughts?

Actually, the fix might be as simple as putting:

config = configuration;

before

createRootNode();

in injectDependencies() method but I think it's worth discussing the 
necessity for the two calls to createRootNode().

> 
> 
> ------------------------------------------------------------------------
> 
> _______________________________________________
> jbosscache-dev mailing list
> jbosscache-dev at lists.jboss.org
> https://lists.jboss.org/mailman/listinfo/jbosscache-dev

-- 
Galder Zamarreño
Sr. Software Maintenance Engineer
JBoss, a division of Red Hat