Marshalling problem w/ 2.2.0.CR5
Well, maybe not CR5, since I haven't tested this. But, as briefly discussed on the dev list I'm seeing a failure in a AS testsuite test w/ a snapshot built earlier in the week against the head of 2.2.X branch. I assume it's still there in CR5
Problem is remote call comes in to delete a node that's previously been passivated to disk. As part of handling that call the node is read from disk; this fails due to not using the correct classloader. Region-based marshalling is used, buddy replication, FileCacheLoader.
Following is some analysis; not complete but as far as I can go for now. To reproduce, checkout the head of the AS, change the JBC version in component-matrix/pom.xml to CR5, build AS and testsuite, and from testsuite dir
./build.sh tests-clustering-field-br
OK, what I' seeing. First the failure:
2008-06-27 12:53:50,846 TRACE [org.jboss.cache.interceptors.ActivationInterceptor] (Incoming-1,192.168.1.145:43241) loadNode /_BUDDY_BACKUP_/127.0.0.1_43238/JSESSION/localhost/http-field-pass/giGN4tImzJAMCoFaHg-gZw__/__JBossInternal__/ATTRIBUTE/TEST_DESER/_ID_/5c4o141-i7090w-fhz2z6jb-1-fhz323cn-2k
2008-06-27 12:53:50,846 TRACE [org.jboss.cache.RegionManager] (Incoming-1,192.168.1.145:43241) Contents of RegionsRegistry: {/_BUDDY_BACKUP_/127.0.0.1_43238=RegionImpl{fqn=/_BUDDY_BACKUP_/127.0.0.1_43238; classloader=null; status=INACTIVE; eviction=true; timerThreadRegistered=true}, /=RegionImpl{fqn=/; classloader=null; status=INACTIVE; eviction=true; timerThreadRegistered=true}, /JSESSION/localhost/http-field-pass=RegionImpl{fqn=/JSESSION/localhost/http-field-pass; classloader=org.jboss.web.tomcat.service.WebCtxLoader$ENCLoader@41fc8c; status=ACTIVE; eviction=false; timerThreadRegistered=false}}
2008-06-27 12:53:50,847 TRACE [org.jboss.cache.RegionManager] (Incoming-1,192.168.1.145:43241) Trying next region /_BUDDY_BACKUP_/127.0.0.1_43238 and got RegionImpl{fqn=/_BUDDY_BACKUP_/127.0.0.1_43238; classloader=null; status=INACTIVE; eviction=true; timerThreadRegistered=true}
2008-06-27 12:53:50,847 TRACE [org.jboss.cache.RegionManager] (Incoming-1,192.168.1.145:43241) Trying next region / and got RegionImpl{fqn=/; classloader=null; status=INACTIVE; eviction=true; timerThreadRegistered=true}
2008-06-27 12:53:50,847 TRACE [org.jboss.cache.marshall.CacheMarshaller210] (Incoming-1,192.168.1.145:43241) Unmarshalled region as null. Not using a context class loader to unmarshall.
2008-06-27 12:53:50,847 TRACE [org.jboss.cache.marshall.CacheMarshaller210] (Incoming-1,192.168.1.145:43241) Unmarshalled regionFqn null from stream
2008-06-27 12:53:50,847 DEBUG [org.jboss.cache.marshall.CacheMarshaller210] (Incoming-1,192.168.1.145:43241) Region does not exist for Fqn null - not using a context classloader.
2008-06-27 12:53:50,851 ERROR [org.jboss.cache.interceptors.TxInterceptor] (Incoming-1,192.168.1.145:43241) prepare failed!
java.lang.ClassNotFoundException: org.jboss.test.cluster.web.DeserializationSensor
at java.net.URLClassLoader$1.run(URLClassLoader.java:200)
at java.security.AccessController.doPrivileged(Native Method)
at java.net.URLClassLoader.findClass(URLClassLoader.java:188)
at java.lang.ClassLoader.loadClass(ClassLoader.java:306)
at sun.misc.Launcher$AppClassLoader.loadClass(Launcher.java:268)
at java.lang.ClassLoader.loadClass(ClassLoader.java:251)
at java.lang.ClassLoader.loadClassInternal(ClassLoader.java:319)
at java.lang.Class.forName0(Native Method)
at java.lang.Class.forName(Class.java:242)
at org.jboss.classloader.spi.base.BaseClassLoaderDomain.loadClass(BaseClassLoaderDomain.java:207)
at org.jboss.classloader.spi.base.BaseClassLoaderDomain.loadClass(BaseClassLoaderDomain.java:1009)
at org.jboss.classloader.spi.base.BaseClassLoader.loadClassFromDomain(BaseClassLoader.java:728)
at org.jboss.classloader.spi.base.BaseClassLoader.loadClass(BaseClassLoader.java:372)
at java.lang.ClassLoader.loadClass(ClassLoader.java:251)
at java.lang.ClassLoader.loadClassInternal(ClassLoader.java:319)
at java.lang.Class.forName0(Native Method)
at java.lang.Class.forName(Class.java:242)
at org.jboss.util.stream.MarshalledValueInputStream.resolveClass(MarshalledValueInputStream.java:62)
at java.io.ObjectInputStream.readNonProxyDesc(ObjectInputStream.java:1544)
at java.io.ObjectInputStream.readClassDesc(ObjectInputStream.java:1466)
at java.io.ObjectInputStream.readOrdinaryObject(ObjectInputStream.java:1699)
at java.io.ObjectInputStream.readObject0(ObjectInputStream.java:1305)
at java.io.ObjectInputStream.readObject(ObjectInputStream.java:348)
at org.jboss.cache.marshall.CacheMarshaller200.unmarshallObject(CacheMarshaller200.java:540)
at org.jboss.cache.marshall.CacheMarshaller200.populateFromStream(CacheMarshaller200.java:750)
at org.jboss.cache.marshall.CacheMarshaller200.unmarshallHashMap(CacheMarshaller200.java:713)
at org.jboss.cache.marshall.CacheMarshaller200.unmarshallObject(CacheMarshaller200.java:571)
at org.jboss.cache.marshall.CacheMarshaller200.unmarshallObject(CacheMarshaller200.java:513)
at org.jboss.cache.marshall.CacheMarshaller200.objectFromObjectStreamRegionBased(CacheMarshaller200.java:202)
at org.jboss.cache.marshall.CacheMarshaller200.objectFromObjectStream(CacheMarshaller200.java:126)
at org.jboss.cache.marshall.VersionAwareMarshaller.objectFromObjectStream(VersionAwareMarshaller.java:326)
at org.jboss.cache.loader.FileCacheLoader.doUnmarshall(FileCacheLoader.java:481)
at org.jboss.cache.loader.AbstractCacheLoader.regionAwareUnmarshall(AbstractCacheLoader.java:214)
at org.jboss.cache.loader.FileCacheLoader.loadAttributes(FileCacheLoader.java:434)
at org.jboss.cache.loader.FileCacheLoader.get(FileCacheLoader.java:201)
at org.jboss.cache.interceptors.CacheLoaderInterceptor.loadData(CacheLoaderInterceptor.java:564)
at org.jboss.cache.interceptors.CacheLoaderInterceptor.loadNode(CacheLoaderInterceptor.java:491)
at org.jboss.cache.interceptors.CacheLoaderInterceptor.loadIfNeeded(CacheLoaderInterceptor.java:305)
at org.jboss.cache.interceptors.CacheLoaderInterceptor.visitPutKeyValueCommand(CacheLoaderInterceptor.java:106)
at org.jboss.cache.interceptors.ActivationInterceptor.visitPutKeyValueCommand(ActivationInterceptor.java:135)
at org.jboss.cache.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:92)
at org.jboss.cache.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:142)
at org.jboss.cache.interceptors.PessimisticLockInterceptor.handlePutCommand(PessimisticLockInterceptor.java:118)
at org.jboss.cache.interceptors.PessimisticLockInterceptor.handlePutKeyValueCommand(PessimisticLockInterceptor.java:86)
at org.jboss.cache.interceptors.base.PostProcessingCommandInterceptor.visitPutKeyValueCommand(PostProcessingCommandInterceptor.java:56)
at org.jboss.cache.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:92)
at org.jboss.cache.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:142)
at org.jboss.cache.interceptors.ReplicationInterceptor.handleCrudMethod(ReplicationInterceptor.java:129)
at org.jboss.cache.interceptors.ReplicationInterceptor.visitPutKeyValueCommand(ReplicationInterceptor.java:86)
at org.jboss.cache.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:92)
at org.jboss.cache.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:142)
at org.jboss.cache.interceptors.base.CommandInterceptor.handleDefault(CommandInterceptor.java:157)
at org.jboss.cache.commands.AbstractVisitor.visitPutKeyValueCommand(AbstractVisitor.java:35)
at org.jboss.cache.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:92)
at org.jboss.cache.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:142)
at org.jboss.cache.interceptors.TxInterceptor.replayModifications(TxInterceptor.java:502)
at org.jboss.cache.interceptors.TxInterceptor.handleRemotePrepare(TxInterceptor.java:382)
at org.jboss.cache.interceptors.TxInterceptor.visitPrepareCommand(TxInterceptor.java:105)
at org.jboss.cache.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:46)
at org.jboss.cache.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:142)
at org.jboss.cache.interceptors.base.CommandInterceptor.handleDefault(CommandInterceptor.java:157)
at org.jboss.cache.commands.AbstractVisitor.visitPrepareCommand(AbstractVisitor.java:110)
at org.jboss.cache.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:46)
at org.jboss.cache.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:142)
at org.jboss.cache.interceptors.InvocationContextInterceptor.handleAll(InvocationContextInterceptor.java:158)
at org.jboss.cache.interceptors.InvocationContextInterceptor.visitPrepareCommand(InvocationContextInterceptor.java:84)
at org.jboss.cache.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:46)
at org.jboss.cache.interceptors.InterceptorChain.invokeRemote(InterceptorChain.java:239)
at org.jboss.cache.commands.remote.ReplicateCommand.processSingleCommand(ReplicateCommand.java:116)
at org.jboss.cache.commands.remote.ReplicateCommand.perform(ReplicateCommand.java:92)
at org.jboss.cache.marshall.CommandAwareRpcDispatcher.executeCommand(CommandAwareRpcDispatcher.java:173)
at org.jboss.cache.marshall.InactiveRegionAwareRpcDispatcher.handle(InactiveRegionAwareRpcDispatcher.java:73)
at org.jgroups.blocks.RequestCorrelator.handleRequest(RequestCorrelator.java:624)
at org.jgroups.blocks.RequestCorrelator.receiveMessage(RequestCorrelator.java:533)
at org.jgroups.blocks.RequestCorrelator.receive(RequestCorrelator.java:365)
at org.jgroups.blocks.MessageDispatcher$ProtocolAdapter.up(MessageDispatcher.java:764)
at org.jgroups.JChannel.up(JChannel.java:1265)
at org.jgroups.stack.ProtocolStack.up(ProtocolStack.java:441)
at org.jgroups.protocols.pbcast.FLUSH.up(FLUSH.java:373)
at org.jgroups.protocols.pbcast.STATE_TRANSFER.up(STATE_TRANSFER.java:144)
at org.jgroups.protocols.FRAG2.up(FRAG2.java:205)
at org.jgroups.protocols.FC.up(FC.java:411)
at org.jgroups.protocols.pbcast.GMS.up(GMS.java:772)
at org.jgroups.protocols.pbcast.STABLE.up(STABLE.java:233)
at org.jgroups.protocols.UNICAST.handleDataReceived(UNICAST.java:627)
at org.jgroups.protocols.UNICAST.up(UNICAST.java:286)
at org.jgroups.protocols.pbcast.NAKACK.up(NAKACK.java:729)
at org.jgroups.protocols.VERIFY_SUSPECT.up(VERIFY_SUSPECT.java:167)
at org.jgroups.protocols.FD.up(FD.java:284)
at org.jgroups.protocols.FD_SOCK.up(FD_SOCK.java:309)
at org.jgroups.protocols.MERGE2.up(MERGE2.java:144)
at org.jgroups.protocols.Discovery.up(Discovery.java:244)
at org.jgroups.protocols.TP$ProtocolAdapter.up(TP.java:2191)
at org.jgroups.protocols.TP.passMessageUp(TP.java:1235)
at org.jgroups.protocols.TP.access$100(TP.java:49)
at org.jgroups.protocols.TP$IncomingPacket.handleMyMessage(TP.java:1802)
at org.jgroups.protocols.TP$IncomingPacket.run(TP.java:1776)
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:650)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:675)
at java.lang.Thread.run(Thread.java:595)
The earlier logging from RegionManager is due to calls from AbstractCacheLoader.regionAwareUnmarshall(), which is trying to find an appropriate classloader to set and fails. I think this comes down to a problem in AbstractCacheLoader.regionAwareMarshall() and regionAwareUnmarshall():
Region r = regionManager == null ? null : regionManager.getRegion(fqn, Region.Type.MARSHALLING, false);
That call won't convert from a BR FQN to a main tree FQN, so it doesn't find the region. Better would be to call a method that does that, a la AbstractMarshaller.getRegion(Fqn):
protected Region getRegion(Fqn fqn)
{
if (fqn == null) return null;
if (buddyFqnTransformer.isBackupFqn(fqn))
{
// Strip out the buddy group portion
fqn = buddyFqnTransformer.getActualFqn(fqn);
}
return regionManager.getRegion(fqn, Region.Type.MARSHALLING, false);
}
That should wrap it up, yes? Problem is I look at the code in 2.1.1.GA and it looks the same, so I don't understand why the test is failing now and not w/ 2.1.1.GA. So I'm missing something important.
Could it be that 2.1.1.GA wouldn't try to load the node from disk when doing the remove, i.e. the problem's been there all along but a behavior change has exposed it?
