1 Reply Latest reply on Jun 28, 2008 8:08 AM by Manik Surtani

    Marshalling problem w/ 2.2.0.CR5

    Brian Stansberry Master

      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?

        • 1. Re: Marshalling problem w/ 2.2.0.CR5
          Manik Surtani Master

          Whether this is the root cause of your problem or not, it is incorrect that buddy regions aren't considered in the abstract CL. I have fixed this and it is in branch 2.2.X, I've just published a new snapshot as well on Maven. See if this works for you? For some reason the AS tests fail sporadically and inconsistently for me, even with 2.2.0.CR5 so not sure if I'm doing something wrong.