Uploaded image for project: 'Application Server 7'
  1. Application Server 7
  2. AS7-3180

Clean shutdown often results in "Problems unmarshalling remote command from byte buffer"

    XMLWordPrintable

Details

    Description

      When shutting down a server from a cluster, it often results in

      WARN [org.infinispan.remoting.transport.jgroups.CommandAwareRpcDispatcher] Problems unmarshalling remote command from byte buffer: org.infinispan.CacheException: Cache manager is either starting up or shutting down but it's not interrupted, so type (id=74) cannot be resolved.

      incluing verbose logging which doesnt seem necessary

      and jgroups logs

      [JBossINF] 12:28:22,392 SEVERE [org.jgroups.protocols.UNICAST2] perf19/web: sender window for perf21/web not found

      is this a real problem? if not, can it be handled more cleanly?

      [JBossINF] 12:28:21,960 INFO  [org.apache.coyote.http11.Http11AprProtocol] (MSC service thread 1-7) Pausing Coyote HTTP/1.1 on http-perf19-10.16.90.56-8080
[JBossINF] 12:28:21,961 INFO  [org.apache.coyote.http11.Http11AprProtocol] (MSC service thread 1-7) Stopping Coyote HTTP/1.1 on http-perf19-10.16.90.56-8080
[JBossINF] 12:28:21,974 INFO  [org.jboss.as.logging] JBAS011503: Restored bootstrap log handlers
[JBossINF] 12:28:21,975 INFO  [org.apache.catalina.core.StandardContext] Container org.apache.catalina.core.ContainerBase.[jboss.web].[default-host].[/] has not been started
[JBossINF] 12:28:22,008 INFO  [org.jboss.as.clustering] JBAS010302: Stopped org.jboss.test.clusterbench.ejb.stateful.LocalStatefulSB cache from sfsb container
[JBossINF] 12:28:22,010 INFO  [org.hornetq.core.server.impl.HornetQServerImpl] HornetQ Server version 2.2.7.Final (HQ_2_2_7_FINAL_AS7, 121) [be9627f1-362f-11e1-986b-d4856468f854] stopped
[JBossINF] 12:28:22,012 INFO  [org.apache.coyote.ajp.AjpAprProtocol] Pausing Coyote AJP/1.3 on ajp-perf19-10.16.90.56-8009
[JBossINF] 12:28:22,012 INFO  [org.apache.coyote.ajp.AjpAprProtocol] Stopping Coyote AJP/1.3 on ajp-perf19-10.16.90.56-8009
[JBossINF] 12:28:22,013 INFO  [org.jboss.as.clustering] JBAS010302: Stopped org.jboss.test.clusterbench.ejb.stateful.RemoteStatefulSBImpl cache from sfsb container
[JBossINF] 12:28:22,022 INFO  [jacorb.poa] POA RootPOA destroyed
[JBossINF] 12:28:22,029 INFO  [org.infinispan.eviction.PassivationManagerImpl] ISPN000029: Passivating all entries to disk
[JBossINF] 12:28:22,029 INFO  [org.infinispan.eviction.PassivationManagerImpl] ISPN000030: Passivated 0 entries in 0 milliseconds
[JBossINF] 12:28:22,030 INFO  [jacorb.orb] prepare ORB for shutdown...
[JBossINF] 12:28:22,030 INFO  [jacorb.orb] ORB going down...
[JBossINF] 12:28:22,031 INFO  [jacorb.orb] ORB shutdown complete
[JBossINF] 12:28:22,032 INFO  [jacorb.orb] ORB run, exit
[JBossINF] 12:28:22,032 INFO  [jacorb.orb.iiop] Listener exited
[JBossINF] 12:28:22,036 INFO  [org.jboss.weld] Stopping weld service
[JBossINF] 12:28:22,038 INFO  [org.infinispan.eviction.PassivationManagerImpl] ISPN000029: Passivating all entries to disk
[JBossINF] 12:28:22,038 INFO  [org.infinispan.eviction.PassivationManagerImpl] ISPN000030: Passivated 0 entries in 0 milliseconds
[JBossINF] 12:28:22,047 INFO  [org.jboss.as.server.deployment] Stopped deployment clusterbench-ee6-ejb.jar in 91ms
[JBossINF] 12:28:22,048 INFO  [org.jboss.as.server.deployment] Stopped deployment clusterbench-ee6-web.war in 91ms
[JBossINF] 12:28:22,049 INFO  [org.jboss.as.server.deployment] Stopped deployment clusterbench-ee6.ear in 97ms
[JBossINF] 12:28:22,057 INFO  [org.jboss.as.clustering] JBAS010302: Stopped registry cache from web container
[JBossINF] 12:28:22,063 INFO  [org.jboss.as.clustering] JBAS010302: Stopped repl cache from web container
[JBossINF] 12:28:22,069 INFO  [org.jboss.as.clustering] JBAS010302: Stopped repl cache from sfsb container
[JBossINF] 12:28:22,336 INFO  [org.infinispan.remoting.transport.jgroups.JGroupsTransport] ISPN000082: Stopping the RpcDispatcher
[JBossINF] 12:28:22,392 SEVERE [org.jgroups.protocols.UNICAST2] perf19/web: sender window for perf21/web not found
[JBossINF] 12:28:22,440 INFO  [org.infinispan.remoting.transport.jgroups.JGroupsTransport] ISPN000082: Stopping the RpcDispatcher
[JBossINF] 12:28:22,441 INFO  [com.arjuna.ats.jbossatx] ARJUNA032018: Destroying TransactionManagerService
[JBossINF] 12:28:22,442 INFO  [com.arjuna.ats.jbossatx] ARJUNA032014: Stopping transaction recovery manager
[JBossINF] 12:28:22,463 WARN  [org.infinispan.remoting.transport.jgroups.CommandAwareRpcDispatcher] Problems unmarshalling remote command from byte buffer: org.infinispan.CacheException: Cache manager is either starting up or shutting down but it's not interrupted, so type (id=74) cannot be resolved.
[JBossINF] 	at org.infinispan.marshall.jboss.ExternalizerTable.readObject(ExternalizerTable.java:257) [infinispan-core-5.1.0.CR1.jar:5.1.0.CR1]
[JBossINF] 	at org.jboss.marshalling.river.RiverUnmarshaller.doReadObject(RiverUnmarshaller.java:351)
[JBossINF] 	at org.jboss.marshalling.river.RiverUnmarshaller.doReadObject(RiverUnmarshaller.java:209)
[JBossINF] 	at org.jboss.marshalling.AbstractObjectInput.readObject(AbstractObjectInput.java:37) [jboss-marshalling-1.3.4.GA.jar:1.3.4.GA]
[JBossINF] 	at org.infinispan.marshall.jboss.AbstractJBossMarshaller.objectFromObjectStream(AbstractJBossMarshaller.java:120) [infinispan-core-5.1.0.CR1.jar:5.1.0.CR1]
[JBossINF] 	at org.infinispan.marshall.VersionAwareMarshaller.objectFromByteBuffer(VersionAwareMarshaller.java:115) [infinispan-core-5.1.0.CR1.jar:5.1.0.CR1]
[JBossINF] 	at org.infinispan.marshall.AbstractDelegatingMarshaller.objectFromByteBuffer(AbstractDelegatingMarshaller.java:79) [infinispan-core-5.1.0.CR1.jar:5.1.0.CR1]
[JBossINF] 	at org.infinispan.remoting.transport.jgroups.MarshallerAdapter.objectFromBuffer(MarshallerAdapter.java:50) [infinispan-core-5.1.0.CR1.jar:5.1.0.CR1]
[JBossINF] 	at org.infinispan.remoting.transport.jgroups.CommandAwareRpcDispatcher.handle(CommandAwareRpcDispatcher.java:139) [infinispan-core-5.1.0.CR1.jar:5.1.0.CR1]
[JBossINF] 	at org.jgroups.blocks.RequestCorrelator.handleRequest(RequestCorrelator.java:447) [jgroups-3.0.1.Final.jar:3.0.1.Final]
[JBossINF] 	at org.jgroups.blocks.RequestCorrelator.receiveMessage(RequestCorrelator.java:354) [jgroups-3.0.1.Final.jar:3.0.1.Final]
[JBossINF] 	at org.jgroups.blocks.RequestCorrelator.receive(RequestCorrelator.java:230) [jgroups-3.0.1.Final.jar:3.0.1.Final]
[JBossINF] 	at org.jgroups.blocks.MessageDispatcher$ProtocolAdapter.up(MessageDispatcher.java:556) [jgroups-3.0.1.Final.jar:3.0.1.Final]
[JBossINF] 	at org.jboss.as.clustering.jgroups.ClassLoaderAwareUpHandler.up(ClassLoaderAwareUpHandler.java:56) [jboss-as-clustering-jgroups-7.1.0.Final-SNAPSHOT.jar:7.1.0.Final-SNAPSHOT]
[JBossINF] 	at org.jgroups.blocks.mux.MuxUpHandler.up(MuxUpHandler.java:130) [jgroups-3.0.1.Final.jar:3.0.1.Final]
[JBossINF] 	at org.jboss.as.clustering.jgroups.MuxChannel$ClassLoaderAwareMuxUpHandler.up(MuxChannel.java:64) [jboss-as-clustering-jgroups-7.1.0.Final-SNAPSHOT.jar:7.1.0.Final-SNAPSHOT]
[JBossINF] 	at org.jgroups.JChannel.up(JChannel.java:716) [jgroups-3.0.1.Final.jar:3.0.1.Final]
[JBossINF] 	at org.jgroups.stack.ProtocolStack.up(ProtocolStack.java:1026) [jgroups-3.0.1.Final.jar:3.0.1.Final]
[JBossINF] 	at org.jgroups.protocols.pbcast.FLUSH.up(FLUSH.java:481) [jgroups-3.0.1.Final.jar:3.0.1.Final]
[JBossINF] 	at org.jgroups.protocols.pbcast.STATE_TRANSFER.up(STATE_TRANSFER.java:178) [jgroups-3.0.1.Final.jar:3.0.1.Final]
[JBossINF] 	at org.jgroups.protocols.FRAG2.up(FRAG2.java:181) [jgroups-3.0.1.Final.jar:3.0.1.Final]
[JBossINF] 	at org.jgroups.protocols.FlowControl.up(FlowControl.java:400) [jgroups-3.0.1.Final.jar:3.0.1.Final]
[JBossINF] 	at org.jgroups.protocols.FlowControl.up(FlowControl.java:418) [jgroups-3.0.1.Final.jar:3.0.1.Final]
[JBossINF] 	at org.jgroups.protocols.pbcast.GMS.up(GMS.java:881) [jgroups-3.0.1.Final.jar:3.0.1.Final]
[JBossINF] 	at org.jgroups.protocols.pbcast.STABLE.up(STABLE.java:244) [jgroups-3.0.1.Final.jar:3.0.1.Final]
[JBossINF] 	at org.jgroups.protocols.UNICAST2.up(UNICAST2.java:383) [jgroups-3.0.1.Final.jar:3.0.1.Final]
[JBossINF] 	at org.jgroups.protocols.pbcast.NAKACK.handleMessage(NAKACK.java:733) [jgroups-3.0.1.Final.jar:3.0.1.Final]
[JBossINF] 	at org.jgroups.protocols.pbcast.NAKACK.up(NAKACK.java:561) [jgroups-3.0.1.Final.jar:3.0.1.Final]
[JBossINF] 	at org.jgroups.protocols.BARRIER.up(BARRIER.java:126) [jgroups-3.0.1.Final.jar:3.0.1.Final]
[JBossINF] 	at org.jgroups.protocols.VERIFY_SUSPECT.up(VERIFY_SUSPECT.java:140) [jgroups-3.0.1.Final.jar:3.0.1.Final]
[JBossINF] 	at org.jgroups.protocols.FD.up(FD.java:273) [jgroups-3.0.1.Final.jar:3.0.1.Final]
[JBossINF] 	at org.jgroups.protocols.FD_SOCK.up(FD_SOCK.java:284) [jgroups-3.0.1.Final.jar:3.0.1.Final]
[JBossINF] 	at org.jgroups.protocols.MERGE2.up(MERGE2.java:205) [jgroups-3.0.1.Final.jar:3.0.1.Final]
[JBossINF] 	at org.jgroups.protocols.Discovery.up(Discovery.java:354) [jgroups-3.0.1.Final.jar:3.0.1.Final]
[JBossINF] 	at org.jgroups.stack.Protocol.up(Protocol.java:358) [jgroups-3.0.1.Final.jar:3.0.1.Final]
[JBossINF] 	at org.jgroups.protocols.TP.passMessageUp(TP.java:1174) [jgroups-3.0.1.Final.jar:3.0.1.Final]
[JBossINF] 	at org.jgroups.protocols.TP$IncomingPacket.handleMyMessage(TP.java:1709) [jgroups-3.0.1.Final.jar:3.0.1.Final]
[JBossINF] 	at org.jgroups.protocols.TP$IncomingPacket.run(TP.java:1691) [jgroups-3.0.1.Final.jar:3.0.1.Final]
[JBossINF] 	at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886) [:1.6.0_29]
[JBossINF] 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908) [:1.6.0_29]
[JBossINF] 	at java.lang.Thread.run(Thread.java:662) [:1.6.0_29]
[JBossINF] 
[JBossINF] 12:28:22,809 INFO  [org.jboss.as] JBoss AS 7.1.0.Final-SNAPSHOT "Flux Capacitor" stopped in 815ms

      Attachments

        Issue Links

          blocks

          Task - Represents a small unit of work that is not end-user facing. ISPN-2063 Remove workaround to handle null commands when channel stops before cache manager

          • Major - To be worked after higher priority work items are addressed. When the severity is high and the effort to change it is low to moderate, this term is chosen. Issues in this category likely have an existing workaround but implementation or execution may be non-trivial.
          • Closed
          is blocked by

          Bug - A problem that impairs or prevents the functions of the product. ISPN-1873 ExternalizerTable not detecting cache manager shutdown for provided channels

          • Major - To be worked after higher priority work items are addressed. When the severity is high and the effort to change it is low to moderate, this term is chosen. Issues in this category likely have an existing workaround but implementation or execution may be non-trivial.
          • Closed

          Bug - A problem that impairs or prevents the functions of the product. ISPN-1926 ExternalizerTable still noisy when being shutdown

          • Major - To be worked after higher priority work items are addressed. When the severity is high and the effort to change it is low to moderate, this term is chosen. Issues in this category likely have an existing workaround but implementation or execution may be non-trivial.
          • Closed

          Component Upgrade - A task tracking an update to a bundled component or revision of component upstream of the project. AS7-3907 Upgrade Infinispan to 5.1.2.FINAL

          • Critical - To be worked on immediately following BLOCKER issues.
          • Closed
          is related to

          Bug - A problem that impairs or prevents the functions of the product. ISPN-2025 NPE in Externalizer on shutdown

          • Critical - To be worked on immediately following BLOCKER issues.
          • Closed
          relates to

          Bug - A problem that impairs or prevents the functions of the product. ISPN-1979 Check whether cache is terminated when resolving object in ExternalizerTable

          • Major - To be worked after higher priority work items are addressed. When the severity is high and the effort to change it is low to moderate, this term is chosen. Issues in this category likely have an existing workaround but implementation or execution may be non-trivial.
          • Closed

          Bug - A problem that impairs or prevents the functions of the product. AS7-3172 Logging incosistency "WARN" vs "WARNING"

          • Minor - To be worked after urgent, high, and medium priorities are resolved. This term is chosen when the severity of the issue is low, or the complexity or effort to correct it may be higher, relatively speaking. For low priority issues, known workarounds exist or are not needed due to the trivial effort needed to address the issue.
          • Closed

          Activity

            People

              pferraro@redhat.com Paul Ferraro
              rhn-engineering-rhusar Radoslav Husar
              Votes:
              0 Vote for this issue
              Watchers:
              6 Start watching this issue

              Dates

                Created:
                Updated:
                Resolved: