4 Replies Latest reply on Sep 19, 2007 12:49 PM by Manik Surtani

    Error when stopping cache.

    Oleg Afanasiev Newbie

      I've encountered a prolem when switching from JBossCache 2.0.0-RC3 to 2.0.0-GA. When I stop cache the logs are flooded with warnings like that:

      2007-09-06 16:34:59,069 WARN + : replication failure with method_call MethodName: _put; MethodIdInteger: 3; Args: (null, /Server3/382982, 1, com.jnetx.cmptest.CMPObject@1ab418e3, true) exception
      java.lang.IllegalStateException: Cache not in STARTED state!
      at org.jboss.cache.CacheImpl.invokeMethod(CacheImpl.java:3929)
      at org.jboss.cache.CacheImpl._replicate(CacheImpl.java:2853)
      at sun.reflect.GeneratedMethodAccessor3.invoke(Unknown Source)
      at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
      at java.lang.reflect.Method.invoke(Method.java:585)
      at org.jgroups.blocks.MethodCall.invoke(MethodCall.java:330)
      at org.jboss.cache.marshall.InactiveRegionAwareRpcDispatcher.handle(InactiveRegionAwareRpcDispatcher.java:77)
      at org.jgroups.blocks.RequestCorrelator.handleRequest(RequestCorrelator.java:654)
      at org.jgroups.blocks.RequestCorrelator.receiveMessage(RequestCorrelator.java:544)
      at org.jgroups.blocks.RequestCorrelator.receive(RequestCorrelator.java:367)
      at org.jgroups.blocks.MessageDispatcher$ProtocolAdapter.up(MessageDispatcher.java:777)
      at org.jgroups.JChannel.up(JChannel.java:1091)
      at org.jgroups.stack.ProtocolStack.up(ProtocolStack.java:382)
      at org.jgroups.stack.ProtocolStack.receiveUpEvent(ProtocolStack.java:398)
      at org.jgroups.stack.Protocol.passUp(Protocol.java:520)
      at org.jgroups.protocols.pbcast.STREAMING_STATE_TRANSFER.up(STREAMING_STATE_TRANSFER.java:280)
      at org.jgroups.stack.Protocol.receiveUpEvent(Protocol.java:470)
      at org.jgroups.stack.Protocol.passUp(Protocol.java:520)
      at org.jgroups.protocols.FRAG2.up(FRAG2.java:197)
      at org.jgroups.stack.Protocol.receiveUpEvent(Protocol.java:470)
      at org.jgroups.stack.Protocol.passUp(Protocol.java:520)
      at org.jgroups.protocols.FC.up(FC.java:422)
      at org.jgroups.stack.Protocol.receiveUpEvent(Protocol.java:470)
      at org.jgroups.stack.Protocol.passUp(Protocol.java:520)
      at org.jgroups.protocols.pbcast.GMS.up(GMS.java:768)
      at org.jgroups.stack.Protocol.receiveUpEvent(Protocol.java:470)
      at org.jgroups.protocols.pbcast.GMS.receiveUpEvent(GMS.java:788)
      at org.jgroups.stack.Protocol.passUp(Protocol.java:520)
      at org.jgroups.protocols.VIEW_SYNC.up(VIEW_SYNC.java:154)
      at org.jgroups.stack.Protocol.receiveUpEvent(Protocol.java:470)
      at org.jgroups.stack.Protocol.passUp(Protocol.java:520)
      at org.jgroups.protocols.pbcast.STABLE.up(STABLE.java:262)
      at org.jgroups.stack.Protocol.receiveUpEvent(Protocol.java:470)
      at org.jgroups.stack.Protocol.passUp(Protocol.java:520)
      at org.jgroups.protocols.UNICAST.up(UNICAST.java:259)
      at org.jgroups.stack.Protocol.receiveUpEvent(Protocol.java:470)
      at org.jgroups.stack.Protocol.passUp(Protocol.java:520)
      at org.jgroups.protocols.pbcast.NAKACK.handleMessage(NAKACK.java:685)
      at org.jgroups.protocols.pbcast.NAKACK.up(NAKACK.java:517)
      at org.jgroups.protocols.pbcast.NAKACK.handleXmitRsp(NAKACK.java:848)
      at org.jgroups.protocols.pbcast.NAKACK.up(NAKACK.java:533)
      at org.jgroups.stack.Protocol.receiveUpEvent(Protocol.java:470)
      at org.jgroups.stack.Protocol.passUp(Protocol.java:520)
      at org.jgroups.protocols.VERIFY_SUSPECT.up(VERIFY_SUSPECT.java:170)
      at org.jgroups.stack.Protocol.receiveUpEvent(Protocol.java:470)
      at org.jgroups.stack.Protocol.passUp(Protocol.java:520)
      at org.jgroups.protocols.FD.up(FD.java:300)
      at org.jgroups.stack.Protocol.receiveUpEvent(Protocol.java:470)
      at org.jgroups.stack.Protocol.passUp(Protocol.java:520)
      at org.jgroups.protocols.FD_SOCK.up(FD_SOCK.java:301)
      at org.jgroups.stack.Protocol.receiveUpEvent(Protocol.java:470)
      at org.jgroups.stack.Protocol.passUp(Protocol.java:520)
      at org.jgroups.protocols.MERGE2.up(MERGE2.java:162)
      at org.jgroups.stack.Protocol.receiveUpEvent(Protocol.java:470)
      at org.jgroups.stack.Protocol.passUp(Protocol.java:520)
      at org.jgroups.protocols.Discovery.up(Discovery.java:225)
      at org.jgroups.stack.Protocol.receiveUpEvent(Protocol.java:470)
      at org.jgroups.stack.Protocol.passUp(Protocol.java:520)
      at org.jgroups.protocols.TP.handleIncomingMessage(TP.java:909)
      at org.jgroups.protocols.TP.handleIncomingPacket(TP.java:851)
      at org.jgroups.protocols.TP.access$400(TP.java:46)
      at org.jgroups.protocols.TP$IncomingPacketHandler.run(TP.java:1297)
      at java.lang.Thread.run(Thread.java:595)

      As soon as the cache started back, this logging disappears and cache keeps working normally.
      This seems to happen because the underlying JChannel is not actually closed on stop(). It keeps receiving replication info and sends them up the stack to the cache. I'm using latest JGroups 2.4.1-SP4.

      The code which is used in JBC is not very correct:

      /**
      * Kills the JGroups channel; an unclean channel disconnect
      */
      public void killChannel()
      {
      if (channel != null)
      {
      channel.close();
      channel.disconnect();
      }
      }

      since channel.disconnect() method does nothing after JChannel has been closed. But I don't understand why it can leas to such disastrous behaviour.