Problem accessing memcached server via Enyim C# client

[lowecg2004]

Hello,

I've fired up two Infinispan instances as per these instructions:

https://docs.jboss.org/author/display/ISPN/Talking+To+Infinispan+Memcached+Servers+From+Non-Java+Clients

Essentially, I have two servers running:

./bin/startServer.sh -r memcached -c etc/config-samples/gui-demo-cache-config.xml -p 12211

./bin/startServer.sh -r memcached -c etc/config-samples/gui-demo-cache-config.xml -p 13211

Using the C# Enyim client, I have the following simple command line test program:

using System;

using Enyim.Caching;

using Enyim.Caching.Memcached;

using System.Net;

using Enyim.Caching.Configuration;

namespace MemcacheClientTest1

{

    class Program

    {

        static void Main(string[] args)

        {

              MemcachedClientConfiguration config = new MemcachedClientConfiguration();

              config.Servers.Add(new IPEndPoint(IPAddress.Loopback, 12211));

              config.Servers.Add(new IPEndPoint(IPAddress.Loopback, 13211));

              config.Protocol = MemcachedProtocol.Text;

              var mc = new MemcachedClient(config);

              mc.Store(StoreMode.Set, "Hello", "World");

              Console.ReadLine();

                    }

          }

}

When calling mc.Store, the client waits for a few seconds before failing with a org.infinispan.manager.NamedCacheNotFoundException.

While on the infinispan server the full stack trace is as follows:

$ ./bin/startServer.sh -r memcached -c etc/config-samples/gui-demo-cache-config.xml -p 13211

2011-10-09 21:51:03,511 WARN  [DefaultCacheManager] (MemcachedServerMaster-1 ([id: 0x00c3358b, /127.0.0.1:13211])) ISPN000156: You are not starting all your caches at the same time. This can lead to p

roblems as asymmetric clusters are not supported, see ISPN-658. We recommend using EmbeddedCacheManager.startCaches() to start all your caches upfront.

2011-10-09 21:51:03,596 ERROR [RpcManagerImpl] (Rehasher,memcachedCache,Ron-Burgundy-11246) ISPN000073: Unexpected error while replicating

org.infinispan.manager.NamedCacheNotFoundException: Cannot process command StateTransferControlCommand{cache=memcachedCache, type=REQUEST_JOIN, sender=Ron-Burgundy-11246, viewId=1, state=N/A} on node

Ron-Burgundy-49518 Cache: memcachedCache

        at org.infinispan.remoting.InboundInvocationHandlerImpl.handle(InboundInvocationHandlerImpl.java:153)

        at org.infinispan.remoting.transport.jgroups.CommandAwareRpcDispatcher.executeCommand(CommandAwareRpcDispatcher.java:160)

        at org.infinispan.remoting.transport.jgroups.CommandAwareRpcDispatcher.handle(CommandAwareRpcDispatcher.java:139)

        at org.jgroups.blocks.RequestCorrelator.handleRequest(RequestCorrelator.java:446)

        at org.jgroups.blocks.RequestCorrelator.receiveMessage(RequestCorrelator.java:353)

        at org.jgroups.blocks.RequestCorrelator.receive(RequestCorrelator.java:229)

        at org.jgroups.blocks.MessageDispatcher$ProtocolAdapter.up(MessageDispatcher.java:556)

        at org.jgroups.JChannel.up(JChannel.java:720)

        at org.jgroups.stack.ProtocolStack.up(ProtocolStack.java:1026)

        at org.jgroups.protocols.FRAG2.up(FRAG2.java:181)

        at org.jgroups.protocols.FlowControl.up(FlowControl.java:418)

        at org.jgroups.protocols.FlowControl.up(FlowControl.java:418)

        at org.jgroups.protocols.pbcast.GMS.up(GMS.java:870)

        at org.jgroups.protocols.pbcast.STABLE.up(STABLE.java:244)

        at org.jgroups.protocols.UNICAST.up(UNICAST.java:297)

        at org.jgroups.protocols.pbcast.NAKACK.handleMessage(NAKACK.java:686)

        at org.jgroups.protocols.pbcast.NAKACK.up(NAKACK.java:547)

        at org.jgroups.protocols.BARRIER.up(BARRIER.java:126)

        at org.jgroups.protocols.FD_ALL.up(FD_ALL.java:171)

        at org.jgroups.protocols.FD_SOCK.up(FD_SOCK.java:273)

        at org.jgroups.protocols.MERGE2.up(MERGE2.java:208)

        at org.jgroups.protocols.Discovery.up(Discovery.java:334)

        at org.jgroups.protocols.TP.passMessageUp(TP.java:1091)

        at org.jgroups.protocols.TP$IncomingPacket.handleMyMessage(TP.java:1646)

        at org.jgroups.protocols.TP$IncomingPacket.run(TP.java:1628)

        at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)

        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)

        at java.lang.Thread.run(Thread.java:662)

2011-10-09 21:51:03,633 ERROR [BaseStateTransferTask] (Rehasher,memcachedCache,Ron-Burgundy-11246) ISPN000145: Error during rehash

org.infinispan.CacheException: org.infinispan.manager.NamedCacheNotFoundException: Cannot process command StateTransferControlCommand{cache=memcachedCache, type=REQUEST_JOIN, sender=Ron-Burgundy-11246

, viewId=1, state=N/A} on node Ron-Burgundy-49518 Cache: memcachedCache

        at org.infinispan.remoting.rpc.RpcManagerImpl.invokeRemotely(RpcManagerImpl.java:144)

        at org.infinispan.remoting.rpc.RpcManagerImpl.invokeRemotely(RpcManagerImpl.java:159)

        at org.infinispan.statetransfer.BaseStateTransferManagerImpl.signalJoinStarted(BaseStateTransferManagerImpl.java:304)

        at org.infinispan.statetransfer.BaseStateTransferManagerImpl.startStateTransfer(BaseStateTransferManagerImpl.java:274)

        at org.infinispan.statetransfer.DistributedStateTransferTask.performRehash(DistributedStateTransferTask.java:85)

        at org.infinispan.statetransfer.BaseStateTransferTask.call(BaseStateTransferTask.java:77)

        at org.infinispan.statetransfer.BaseStateTransferTask.call(BaseStateTransferTask.java:43)

        at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)

        at java.util.concurrent.FutureTask.run(FutureTask.java:138)

        at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)

        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)

        at java.lang.Thread.run(Thread.java:662)

Caused by: org.infinispan.manager.NamedCacheNotFoundException: Cannot process command StateTransferControlCommand{cache=memcachedCache, type=REQUEST_JOIN, sender=Ron-Burgundy-11246, viewId=1, state=N/

A} on node Ron-Burgundy-49518 Cache: memcachedCache

        at org.infinispan.remoting.InboundInvocationHandlerImpl.handle(InboundInvocationHandlerImpl.java:153)

        at org.infinispan.remoting.transport.jgroups.CommandAwareRpcDispatcher.executeCommand(CommandAwareRpcDispatcher.java:160)

        at org.infinispan.remoting.transport.jgroups.CommandAwareRpcDispatcher.handle(CommandAwareRpcDispatcher.java:139)

        at org.jgroups.blocks.RequestCorrelator.handleRequest(RequestCorrelator.java:446)

        at org.jgroups.blocks.RequestCorrelator.receiveMessage(RequestCorrelator.java:353)

        at org.jgroups.blocks.RequestCorrelator.receive(RequestCorrelator.java:229)

        at org.jgroups.blocks.MessageDispatcher$ProtocolAdapter.up(MessageDispatcher.java:556)

        at org.jgroups.JChannel.up(JChannel.java:720)

        at org.jgroups.stack.ProtocolStack.up(ProtocolStack.java:1026)

        at org.jgroups.protocols.FRAG2.up(FRAG2.java:181)

        at org.jgroups.protocols.FlowControl.up(FlowControl.java:418)

        at org.jgroups.protocols.FlowControl.up(FlowControl.java:418)

        at org.jgroups.protocols.pbcast.GMS.up(GMS.java:870)

        at org.jgroups.protocols.pbcast.STABLE.up(STABLE.java:244)

        at org.jgroups.protocols.UNICAST.up(UNICAST.java:297)

        at org.jgroups.protocols.pbcast.NAKACK.handleMessage(NAKACK.java:686)

        at org.jgroups.protocols.pbcast.NAKACK.up(NAKACK.java:547)

        at org.jgroups.protocols.BARRIER.up(BARRIER.java:126)

        at org.jgroups.protocols.FD_ALL.up(FD_ALL.java:171)

        at org.jgroups.protocols.FD_SOCK.up(FD_SOCK.java:273)

        at org.jgroups.protocols.MERGE2.up(MERGE2.java:208)

        at org.jgroups.protocols.Discovery.up(Discovery.java:334)

        at org.jgroups.protocols.TP.passMessageUp(TP.java:1091)

        at org.jgroups.protocols.TP$IncomingPacket.handleMyMessage(TP.java:1646)

        at org.jgroups.protocols.TP$IncomingPacket.run(TP.java:1628)

        ... 3 more

2011-10-09 21:52:03,740 ERROR [InvocationContextInterceptor] (MemcachedServerWorker-1-10) ISPN000136: Execution error

java.lang.NullPointerException

        at org.infinispan.distribution.DistributionManagerImpl.getLocality(DistributionManagerImpl.java:119)

        at org.infinispan.interceptors.DistributionInterceptor.remoteGetAndStoreInL1(DistributionInterceptor.java:170)

        at org.infinispan.interceptors.DistributionInterceptor.remoteGetBeforeWrite(DistributionInterceptor.java:436)

        at org.infinispan.interceptors.DistributionInterceptor.handleWriteCommand(DistributionInterceptor.java:450)

        at org.infinispan.interceptors.DistributionInterceptor.visitPutKeyValueCommand(DistributionInterceptor.java:242)

        at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:77)

        at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:119)

        at org.infinispan.interceptors.EntryWrappingInterceptor.invokeNextAndApplyChanges(EntryWrappingInterceptor.java:181)

        at org.infinispan.interceptors.EntryWrappingInterceptor.visitPutKeyValueCommand(EntryWrappingInterceptor.java:136)

        at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:77)

        at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:119)

        at org.infinispan.interceptors.locking.NonTransactionalLockingInterceptor.visitPutKeyValueCommand(NonTransactionalLockingInterceptor.java:59)

        at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:77)

        at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:119)

        at org.infinispan.interceptors.base.CommandInterceptor.handleDefault(CommandInterceptor.java:133)

        at org.infinispan.commands.AbstractVisitor.visitPutKeyValueCommand(AbstractVisitor.java:60)

        at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:77)

        at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:119)

        at org.infinispan.interceptors.base.CommandInterceptor.handleDefault(CommandInterceptor.java:133)

        at org.infinispan.commands.AbstractVisitor.visitPutKeyValueCommand(AbstractVisitor.java:60)

        at org.infinispan.interceptors.StateTransferLockInterceptor.visitPutKeyValueCommand(StateTransferLockInterceptor.java:110)

        at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:77)

        at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:119)

        at org.infinispan.interceptors.CacheMgmtInterceptor.visitPutKeyValueCommand(CacheMgmtInterceptor.java:114)

        at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:77)

        at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:119)

        at org.infinispan.interceptors.InvocationContextInterceptor.handleAll(InvocationContextInterceptor.java:104)

        at org.infinispan.interceptors.InvocationContextInterceptor.handleDefault(InvocationContextInterceptor.java:64)

        at org.infinispan.commands.AbstractVisitor.visitPutKeyValueCommand(AbstractVisitor.java:60)

        at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:77)

        at org.infinispan.interceptors.InterceptorChain.invoke(InterceptorChain.java:318)

        at org.infinispan.CacheImpl.executeCommandAndCommitIfNeeded(CacheImpl.java:903)

        at org.infinispan.CacheImpl.put(CacheImpl.java:620)

        at org.infinispan.CacheImpl.put(CacheImpl.java:612)

        at org.infinispan.server.core.AbstractProtocolDecoder.put(AbstractProtocolDecoder.scala:185)

        at org.infinispan.server.core.AbstractProtocolDecoder.decodeValue(AbstractProtocolDecoder.scala:141)

        at org.infinispan.server.core.AbstractProtocolDecoder.decode(AbstractProtocolDecoder.scala:71)

        at org.infinispan.server.core.AbstractProtocolDecoder.decode(AbstractProtocolDecoder.scala:45)

        at org.jboss.netty.handler.codec.replay.ReplayingDecoder.callDecode(ReplayingDecoder.java:471)

        at org.jboss.netty.handler.codec.replay.ReplayingDecoder.messageReceived(ReplayingDecoder.java:444)

        at org.infinispan.server.core.AbstractProtocolDecoder.messageReceived(AbstractProtocolDecoder.scala:349)

        at org.jboss.netty.channel.SimpleChannelUpstreamHandler.handleUpstream(SimpleChannelUpstreamHandler.java:80)

        at org.jboss.netty.channel.DefaultChannelPipeline.sendUpstream(DefaultChannelPipeline.java:545)

        at org.jboss.netty.channel.DefaultChannelPipeline.sendUpstream(DefaultChannelPipeline.java:540)

        at org.jboss.netty.channel.Channels.fireMessageReceived(Channels.java:274)

        at org.jboss.netty.channel.Channels.fireMessageReceived(Channels.java:261)

        at org.jboss.netty.channel.socket.nio.NioWorker.read(NioWorker.java:350)

        at org.jboss.netty.channel.socket.nio.NioWorker.processSelectedKeys(NioWorker.java:281)

        at org.jboss.netty.channel.socket.nio.NioWorker.run(NioWorker.java:201)

        at org.jboss.netty.util.ThreadRenamingRunnable.run(ThreadRenamingRunnable.java:108)

        at org.jboss.netty.util.internal.IoWorkerRunnable.run(IoWorkerRunnable.java:46)

        at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)

        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)

        at java.lang.Thread.run(Thread.java:662)

2011-10-09 22:02:14,508 ERROR [MemcachedDecoder] (MemcachedServerWorker-1-11) ISPN005003: Exception reported

java.nio.channels.ClosedChannelException

        at org.jboss.netty.channel.socket.nio.NioWorker.cleanUpWriteBuffer(NioWorker.java:637)

        at org.jboss.netty.channel.socket.nio.NioWorker.close(NioWorker.java:593)

        at org.jboss.netty.channel.socket.nio.NioWorker.write0(NioWorker.java:513)

        at org.jboss.netty.channel.socket.nio.NioWorker.writeFromUserCode(NioWorker.java:388)

        at org.jboss.netty.channel.socket.nio.NioServerSocketPipelineSink.handleAcceptedSocket(NioServerSocketPipelineSink.java:137)

        at org.jboss.netty.channel.socket.nio.NioServerSocketPipelineSink.eventSunk(NioServerSocketPipelineSink.java:76)

        at org.jboss.netty.channel.Channels.write(Channels.java:611)

        at org.jboss.netty.channel.Channels.write(Channels.java:578)

        at org.jboss.netty.channel.AbstractChannel.write(AbstractChannel.java:259)

        at org.infinispan.server.core.AbstractProtocolDecoder.exceptionCaught(AbstractProtocolDecoder.scala:257)

        at org.jboss.netty.channel.Channels.fireExceptionCaught(Channels.java:432)

        at org.jboss.netty.channel.socket.nio.NioWorker.read(NioWorker.java:332)

        at org.jboss.netty.channel.socket.nio.NioWorker.processSelectedKeys(NioWorker.java:281)

        at org.jboss.netty.channel.socket.nio.NioWorker.run(NioWorker.java:201)

        at org.jboss.netty.util.internal.IoWorkerRunnable.run(IoWorkerRunnable.java:46)

        at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)

        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)

        at java.lang.Thread.run(Thread.java:662)

Am I missing something with my configuration?

I've tried versions 5.0.1.Final and 5.1.0.beta1

Regards,

Chris.

[lowecg2004]

This looks as if it might be down to the dreaded ISPN-658.  With this in mind I tried to try and get around the issue (naively perhaps?) by creating a named cache called "memcacheCache" on each node but this also failed:

<namedCache name="memcachedCache">

        <jmxStatistics enabled="true"/>

        <clustering mode="distribution">

                <l1 enabled="true" lifespan="60000"/>

                <hash numOwners="2" rehashRpcTimeout="120000"/>

                <sync/>

        </clustering>

</namedCache>

Despite the above config, I just see a log entry like this:

2011-10-10 14:36:00,269 DEBUG [CacheImpl] (InfinispanServer-Main) Started cache ___defaultcache on DEV11-PC-21893

There is no log entry related to memcachedCache and I get the same exception messages as per my original post.

Finally, if I fire up just one node then I can interact with Infinispan without a problem.  But the documentation states that I should be able to run Infinispan as a cluster - should that still be the case?

Regards,

Chris.

[galder.zamarreno]

Chris, I think there's a bug here with regards to the definition of memcachedCache. It currently happens when a decoder is built. IOW, it gets defined when a request comes through rather than when the server is started. I'll create a JIRA for this.

[lowecg2004]

Thanks for the reply Galder.  Please let me know if I can be of assistance with this with either implementation or testing.

Chris.