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

[Manik Surtani]

On 3 Mar 2009, at 22:14, Brian Stansberry wrote:

> I kind of got lost in the details there, but I don't think that  
> affects my opinion. ;)
>
> IMHO trying to do complex stuff in toString() is asking for trouble.  
> Either DataContainerImpl.toString() or  
> CacheInvocationDelegate.toString() should stop calling into  
> arbitrarily complex code and just output basic info.

Yup.  Also, this is a known issue and is fixed in 3.0.3.GA:

https://jira.jboss.org/jira/browse/JBCACHE-1478


> 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?
>> ------------------------------------------------------------------------
>> _______________________________________________
>> jbosscache-dev mailing list
>> jbosscache-dev at lists.jboss.org
>> https://lists.jboss.org/mailman/listinfo/jbosscache-dev
>
>
> -- 
> Brian Stansberry
> Lead, AS Clustering
> JBoss, a division of Red Hat
> brian.stansberry at redhat.com
> _______________________________________________
> jbosscache-dev mailing list
> jbosscache-dev at lists.jboss.org
> https://lists.jboss.org/mailman/listinfo/jbosscache-dev

--
Manik Surtani
Lead, JBoss Cache
http://www.jbosscache.org
manik at jboss.org




-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://lists.jboss.org/pipermail/jbosscache-dev/attachments/20090303/103fac76/attachment.html