JBossDeveloper

 

Fixed the main issue, which is essentially a missing null check. JBCACHE-1431.

This is in trunk, so if you get the srcs from svn and build it yourself, you will see the fix.

Checked out the trunk and re-ran the fun.

Tried both in 2.x format and 3.x format. Same result. When in debug mode the request works fine, when not in debug mode i dont get any result from the remote cache.

Log output is here

6:14:21,060 [main] INFO jmx.PlatformMBeanServerRegistration - JBossCache MBeans were successfully registered to the platform mbean server.
16:14:21,076 [main] INFO jgroups.JChannel - JGroups version: 2.6.5.GA
16:14:21,294 [main] WARN cache.RPCManagerImpl - You have disabled jgroups's message bundling, which is not recommended for async replication. If there is no particular reason for this we strongly recommend to enable message bundling in JGroups config (enable_bundling="true").

-------------------------------------------------------
GMS: address is 10.251.153.36:1312
-------------------------------------------------------
16:14:23,341 [main] INFO cache.RPCManagerImpl - Received new cluster view: [10.251.153.36:1312|0] [10.251.153.36:1312]
16:14:23,357 [main] INFO cache.RPCManagerImpl - Cache local address is 10.251.153.36:1312
16:14:23,357 [main] INFO factories.ComponentRegistry - JBoss Cache version: JBossCache 'Naga' 3.0.0-SNAPSHOT
16:14:23,482 [main] INFO jmx.PlatformMBeanServerRegistration - JBossCache MBeans were successfully registered to the platform mbean server.
16:14:23,482 [main] INFO jgroups.JChannel - JGroups version: 2.6.5.GA
16:14:23,497 [main] WARN cache.RPCManagerImpl - You have disabled jgroups's message bundling, which is not recommended for async replication. If there is no particular reason for this we strongly recommend to enable message bundling in JGroups config (enable_bundling="true").

-------------------------------------------------------
GMS: address is 10.251.153.36:1314
-------------------------------------------------------
16:14:23,576 [Incoming-1,10.251.153.36:1312] INFO cache.RPCManagerImpl - Received new cluster view: [10.251.153.36:1312|1] [10.251.153.36:1312, 10.251.153.36:1314]
16:14:23,576 [main] INFO cache.RPCManagerImpl - Received new cluster view: [10.251.153.36:1312|1] [10.251.153.36:1312, 10.251.153.36:1314]
16:14:23,591 [main] INFO cache.RPCManagerImpl - Cache local address is 10.251.153.36:1314
16:14:23,591 [main] INFO factories.ComponentRegistry - JBoss Cache version: JBossCache 'Naga' 3.0.0-SNAPSHOT
16:14:23,591 [main] TRACE loader.ClusteredCacheLoader - cache=10.251.153.36:1312; calling with ExistsCommand{fqn=/client/007}
16:14:23,591 [main] TRACE loader.ClusteredCacheLoader - got responses []
Got data from cache {CLIENT=BOND,JAMES}
Lets test ClusteredCacheLoader
16:14:23,607 [main] TRACE loader.ClusteredCacheLoader - cache=10.251.153.36:1314; calling with ExistsCommand{fqn=/client/007}
16:14:23,607 [main] TRACE loader.ClusteredCacheLoader - got responses []
Failed to get data from remote cache???
16:14:23,607 [main] INFO cache.RPCManagerImpl - Disconnecting and closing the Channel
16:14:23,607 [Incoming-1,10.251.153.36:1314] INFO cache.RPCManagerImpl - Received new cluster view: [10.251.153.36:1312|2] [10.251.153.36:1314]
16:14:23,607 [Incoming-1,10.251.153.36:1314] WARN pbcast.NAKACK - 10.251.153.36:1314] discarded message from non-member 10.251.153.36:1312, my view is [10.251.153.36:1312|2] [10.251.153.36:1314]
16:14:23,607 [Incoming-1,10.251.153.36:1314] WARN pbcast.NAKACK - 10.251.153.36:1314] discarded message from non-member 10.251.153.36:1312, my view is [10.251.153.36:1312|2] [10.251.153.36:1314]
16:14:23,622 [main] INFO cache.RPCManagerImpl - Stopping the RpcDispatcher
16:14:23,638 [main] INFO cache.RPCManagerImpl - Disconnecting and closing the Channel
16:14:23,638 [main] INFO cache.RPCManagerImpl - Stopping the RpcDispatcher

When run in debug mode

16:20:10,017 [main] INFO jmx.PlatformMBeanServerRegistration - JBossCache MBeans were successfully registered to the platform mbean server.
16:20:10,049 [main] INFO jgroups.JChannel - JGroups version: 2.6.5.GA
16:20:10,345 [main] WARN cache.RPCManagerImpl - You have disabled jgroups's message bundling, which is not recommended for async replication. If there is no particular reason for this we strongly recommend to enable message bundling in JGroups config (enable_bundling="true").

-------------------------------------------------------
GMS: address is 10.251.153.36:1350
-------------------------------------------------------
16:20:12,408 [main] INFO cache.RPCManagerImpl - Received new cluster view: [10.251.153.36:1350|0] [10.251.153.36:1350]
16:20:12,408 [main] INFO cache.RPCManagerImpl - Cache local address is 10.251.153.36:1350
16:20:12,408 [main] INFO factories.ComponentRegistry - JBoss Cache version: JBossCache 'Naga' 3.0.0-SNAPSHOT
16:20:18,001 [main] INFO jmx.PlatformMBeanServerRegistration - JBossCache MBeans were successfully registered to the platform mbean server.
16:20:18,001 [main] INFO jgroups.JChannel - JGroups version: 2.6.5.GA
16:20:18,048 [main] WARN cache.RPCManagerImpl - You have disabled jgroups's message bundling, which is not recommended for async replication. If there is no particular reason for this we strongly recommend to enable message bundling in JGroups config (enable_bundling="true").

-------------------------------------------------------
GMS: address is 10.251.153.36:1352
-------------------------------------------------------
16:20:18,173 [Incoming-1,10.251.153.36:1350] INFO cache.RPCManagerImpl - Received new cluster view: [10.251.153.36:1350|1] [10.251.153.36:1350, 10.251.153.36:1352]
16:20:18,189 [main] INFO cache.RPCManagerImpl - Received new cluster view: [10.251.153.36:1350|1] [10.251.153.36:1350, 10.251.153.36:1352]
16:20:18,205 [main] INFO cache.RPCManagerImpl - Cache local address is 10.251.153.36:1352
16:20:18,205 [main] INFO factories.ComponentRegistry - JBoss Cache version: JBossCache 'Naga' 3.0.0-SNAPSHOT
16:20:22,579 [main] TRACE loader.ClusteredCacheLoader - cache=10.251.153.36:1350; calling with ExistsCommand{fqn=/client/007}
16:20:22,579 [main] TRACE loader.ClusteredCacheLoader - got responses []
16:20:23,392 [EvictionTimer-0] WARN eviction.ExpirationAlgorithm - No expiration key 'expiration' for Node: /client/007
Got data from cache {CLIENT=BOND,JAMES}
Lets test ClusteredCacheLoader
16:20:25,314 [EvictionTimer-1] WARN eviction.ExpirationAlgorithm - No expiration key 'expiration' for Node: /client/007
Got data from remote cache {CLIENT=BOND,JAMES}
16:20:29,001 [main] INFO cache.RPCManagerImpl - Disconnecting and closing the Channel
16:20:29,017 [Incoming-1,10.251.153.36:1352] INFO cache.RPCManagerImpl - Received new cluster view: [10.251.153.36:1350|2] [10.251.153.36:1352]
16:20:29,017 [Incoming-1,10.251.153.36:1352] WARN pbcast.NAKACK - 10.251.153.36:1352] discarded message from non-member 10.251.153.36:1350, my view is [10.251.153.36:1350|2] [10.251.153.36:1352]
16:20:29,032 [main] INFO cache.RPCManagerImpl - Stopping the RpcDispatcher
16:20:29,064 [main] INFO cache.RPCManagerImpl - Disconnecting and closing the Channel
16:20:29,079 [main] INFO cache.RPCManagerImpl - Stopping the RpcDispatcher

Tmeout on the clustered cache loader is set to 15 seconds!!

Any ideas on why I would see this

Unexpected error occured on server side. Unable to recover to make the request.
java.util.concurrent.RejectedExecutionException
 at java.util.concurrent.ThreadPoolExecutor$AbortPolicy.rejectedExecution(ThreadPoolExecutor.java:1759)
 at java.util.concurrent.ThreadPoolExecutor.reject(ThreadPoolExecutor.java:767)
 at java.util.concurrent.ThreadPoolExecutor.execute(ThreadPoolExecutor.java:658)
 at java.util.concurrent.AbstractExecutorService.submit(AbstractExecutorService.java:92)
 at org.jboss.cache.marshall.CommandAwareRpcDispatcher.invokeRemoteCommands(CommandAwareRpcDispatcher.java:167)
 at org.jboss.cache.RPCManagerImpl.callRemoteMethods(RPCManagerImpl.java:458)
 at org.jboss.cache.loader.ClusteredCacheLoader.callRemote(ClusteredCacheLoader.java:135)
 at org.jboss.cache.loader.ClusteredCacheLoader.exists(ClusteredCacheLoader.java:211)
 at org.jboss.cache.interceptors.CacheLoaderInterceptor.loadIfNeeded(CacheLoaderInterceptor.java:288)
 at org.jboss.cache.interceptors.CacheLoaderInterceptor.visitGetKeyValueCommand(CacheLoaderInterceptor.java:158)
 at org.jboss.cache.commands.read.GetKeyValueCommand.acceptVisitor(GetKeyValueCommand.java:97)
 at org.jboss.cache.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116)
 at org.jboss.cache.interceptors.base.CommandInterceptor.handleDefault(CommandInterceptor.java:131)
 at org.jboss.cache.commands.AbstractVisitor.visitGetKeyValueCommand(AbstractVisitor.java:110)
 at org.jboss.cache.commands.read.GetKeyValueCommand.acceptVisitor(GetKeyValueCommand.java:97)
 at org.jboss.cache.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116)
 at org.jboss.cache.interceptors.base.CommandInterceptor.handleDefault(CommandInterceptor.java:131)
 at org.jboss.cache.commands.AbstractVisitor.visitGetKeyValueCommand(AbstractVisitor.java:110)
 at org.jboss.cache.commands.read.GetKeyValueCommand.acceptVisitor(GetKeyValueCommand.java:97)
 at org.jboss.cache.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116)
 at org.jboss.cache.interceptors.TxInterceptor.attachGtxAndPassUpChain(TxInterceptor.java:284)
 at org.jboss.cache.interceptors.TxInterceptor.handleDefault(TxInterceptor.java:271)
 at org.jboss.cache.commands.AbstractVisitor.visitGetKeyValueCommand(AbstractVisitor.java:110)
 at org.jboss.cache.commands.read.GetKeyValueCommand.acceptVisitor(GetKeyValueCommand.java:97)
 at org.jboss.cache.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116)
 at org.jboss.cache.interceptors.CacheMgmtInterceptor.visitGetKeyValueCommand(CacheMgmtInterceptor.java:77)
 at org.jboss.cache.commands.read.GetKeyValueCommand.acceptVisitor(GetKeyValueCommand.java:97)
 at org.jboss.cache.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116)
 at org.jboss.cache.interceptors.InvocationContextInterceptor.handleAll(InvocationContextInterceptor.java:178)
 at org.jboss.cache.interceptors.InvocationContextInterceptor.handleDefault(InvocationContextInterceptor.java:130)
 at org.jboss.cache.commands.AbstractVisitor.visitGetKeyValueCommand(AbstractVisitor.java:110)
 at org.jboss.cache.commands.read.GetKeyValueCommand.acceptVisitor(GetKeyValueCommand.java:97)
 at org.jboss.cache.interceptors.InterceptorChain.invoke(InterceptorChain.java:265)
 at org.jboss.cache.invocation.CacheInvocationDelegate.get(CacheInvocationDelegate.java:448)

Happening with the CR2 cut , will look into trying to replicate it.

 

Do you still see this with CR3? Have you been able to reproduce it?

I havent had the chance to look at it since then but that exception was getting thrown quite frequently under very little load. So it wasnt just a once off thing.

Will post more on it when i get to it.

Cheers,
LL