8 Replies Latest reply: Jul 5, 2012 6:16 PM by dex chen RSS

Failed to prepare view exceptions

dex chen Novice

I saw lot (re-curring) cache view exceptions (below) when I start up a 3 node cluster.

I am running ISPN 5.1.3 final with replication mode, and jgroup-tcp config.

 

I did not rember seeing  this with 5.1.1.  Is this related to changes to 5.1.3?

 

What is the root cause? and what should I do to track this down?

 

thanks,

 

=======================================

 

2012-04-10/12:13:45.714/MDT

[CacheViewInstaller-3,portal1.net-1609] ERROR

org.infinispan.cacheviews.CacheViewsManagerImpl[263] - ISPN000172: Failed

to prepare view CacheView{viewId=832,

members=[portal1.net-1609, portal2.net-11982]}

for cache  ispn-cipherkey, rolling back to view CacheView{viewId=831,

members=[portal1.net-1609]}

java.util.concurrent.ExecutionException: org.infinispan.CacheException:

java.lang.IllegalStateException: Cannot prepare new view

CacheView{viewId=832, members=[portal1.net-1609,

portal2.net-11982]} on cache ispn-cipherkey, we have already

committed view CacheView{viewId=844, members=[]}

        at java.util.concurrent.FutureTask$Sync.innerGet(FutureTask.java:262)

        at java.util.concurrent.FutureTask.get(FutureTask.java:119)

        at

org.infinispan.cacheviews.CacheViewsManagerImpl.clusterPrepareView(CacheViewsManagerImpl.java:318)

        at

org.infinispan.cacheviews.CacheViewsManagerImpl.clusterInstallView(CacheViewsManagerImpl.java:249)

        at

org.infinispan.cacheviews.CacheViewsManagerImpl$ViewInstallationTask.call(CacheViewsManagerImpl.java:875)

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

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

        at

java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)

        at

java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)

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

Caused by: org.infinispan.CacheException: java.lang.IllegalStateException:

Cannot prepare new view CacheView{viewId=832,

members=[portal1.net-1609, portal2.net-11982]}

on cache ispn-cipherkey, we have already committed view

CacheView{viewId=844, members=[]}

        at org.infinispan.util.Util.rewrapAsCacheException(Util.java:524)

        at

org.infinispan.remoting.transport.jgroups.CommandAwareRpcDispatcher.invokeRemoteCommand(CommandAwareRpcDispatcher.java:172)

        at

org.infinispan.remoting.transport.jgroups.JGroupsTransport.invokeRemotely(JGroupsTransport.java:488)

        at

org.infinispan.cacheviews.CacheViewsManagerImpl$2.call(CacheViewsManagerImpl.java:302)

        at

org.infinispan.cacheviews.CacheViewsManagerImpl$2.call(CacheViewsManagerImpl.java:299)

        ... 5 more

Caused by: java.lang.IllegalStateException: Cannot prepare new view

CacheView{viewId=832, members=[portal1.net-1609,

portal2.net-11982]} on cache ispn-cipherkey, we have already

committed view CacheView{viewId=844, members=[]}

        at

org.infinispan.cacheviews.CacheViewInfo.prepareView(CacheViewInfo.java:107)

        at

org.infinispan.cacheviews.CacheViewsManagerImpl.handlePrepareView(CacheViewsManagerImpl.java:481)

        at

org.infinispan.commands.control.CacheViewControlCommand.perform(CacheViewControlCommand.java:125)

        at

org.infinispan.remoting.InboundInvocationHandlerImpl.handle(InboundInvocationHandlerImpl.java:95)

        at

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

        at

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

        at

org.jgroups.blocks.RequestCorrelator.handleRequest(RequestCorrelator.java:456)

        at

org.jgroups.blocks.RequestCorrelator.receiveMessage(RequestCorrelator.java:363)

        at

org.jgroups.blocks.RequestCorrelator.receive(RequestCorrelator.java:238)

        at

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

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

        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:400)

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

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

        at org.jgroups.protocols.UNICAST2.handleDataReceived(UNICAST2.java:759)

        at org.jgroups.protocols.UNICAST2.up(UNICAST2.java:365)

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

        at org.jgroups.protocols.VERIFY_SUSPECT.up(VERIFY_SUSPECT.java:143)

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

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

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

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

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

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

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

        ... 3 more

2012-04-10/12:13:46.715/MDT

  • 1. Re: Failed to prepare view exceptions
    Dan Berindei Apprentice

    Dex, could you create a JIRA and post some logs with TRACE enabled for org.infinispan?

    We had a similar bug during 5.1.0 betas(https://issues.jboss.org/browse/ISPN-1571), but we didn't see anything similar happening in 5.1.3.FINAL.

  • 2. Re: Failed to prepare view exceptions
    dex chen Novice

    I created the bug for this (ISPN-1996).

  • 3. Re: Failed to prepare view exceptions
    Dan Berindei Apprentice

    Dex, are you still able to reproduce this?

  • 4. Re: Failed to prepare view exceptions
    dex chen Novice

    I have not seen this for while. I'll keep an eye on this. I'll update this when I see it again.

  • 5. Re: Failed to prepare view exceptions
    Eric Neilsen Newbie

    I just saw that error in our production enviornment (JBoss 7.1.1) using infinispan 5.1.2

     

    15:49:28,621 ERROR [org.infinispan.cacheviews.CacheViewsManagerImpl] (CacheViewInstaller-2,app01/attask) ISPN000172: Failed to prepare view CacheView{viewId=3, members=[app01/attask]} for cache  SESSION, rolling back to view CacheView{viewId=2, members=[]}: java.util.concurrent.ExecutionException: java.lang.IllegalStateException: Trying to block write commands but they are already blocked for view 57

              at java.util.concurrent.FutureTask$Sync.innerGet(FutureTask.java:232) [rt.jar:1.6.0_30]

              at java.util.concurrent.FutureTask.get(FutureTask.java:91) [rt.jar:1.6.0_30]

              at org.infinispan.cacheviews.CacheViewsManagerImpl.clusterPrepareView(CacheViewsManagerImpl.java:322)

              at org.infinispan.cacheviews.CacheViewsManagerImpl.clusterInstallView(CacheViewsManagerImpl.java:250)

              at org.infinispan.cacheviews.CacheViewsManagerImpl$ViewInstallationTask.call(CacheViewsManagerImpl.java:876)

              at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303) [rt.jar:1.6.0_30]

              at java.util.concurrent.FutureTask.run(FutureTask.java:138) [rt.jar:1.6.0_30]

              at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886) [rt.jar:1.6.0_30]

              at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908) [rt.jar:1.6.0_30]

              at java.lang.Thread.run(Thread.java:662) [rt.jar:1.6.0_30]

    Caused by: java.lang.IllegalStateException: Trying to block write commands but they are already blocked for view 57

              at org.infinispan.statetransfer.StateTransferLockImpl.blockNewTransactions(StateTransferLockImpl.java:233)

              at org.infinispan.statetransfer.DistributedStateTransferTask.doPerformStateTransfer(DistributedStateTransferTask.java:107)

              at org.infinispan.statetransfer.BaseStateTransferTask.performStateTransfer(BaseStateTransferTask.java:93)

              at org.infinispan.statetransfer.BaseStateTransferManagerImpl.prepareView(BaseStateTransferManagerImpl.java:330)

              at org.infinispan.cacheviews.CacheViewsManagerImpl.handlePrepareView(CacheViewsManagerImpl.java:486)

              at org.infinispan.cacheviews.CacheViewsManagerImpl$3.call(CacheViewsManagerImpl.java:313)

              ... 5 more

  • 6. Re: Failed to prepare view exceptions
    Dan Berindei Apprentice

    Eric, we have an issue in JIRA for this (https://issues.jboss.org/browse/ISPN-1996), but we don't have enough information to find the root cause yet.

     

    I won't ask you to enable trace logging in production, but could you upload the logs you have from all your nodes? The error you posted looks like it happened after the cluster was already in a bad shape ("view 57"), we need to see how the problems started. Your Infinispan and JGroups configuration would also be useful.

  • 7. Re: Failed to prepare view exceptions
    Eric Neilsen Newbie

    <subsystem xmlns="urn:jboss:domain:infinispan:1.2" default-cache-container="cluster">

                <cache-container name="cluster" aliases="ha-partition" default-cache="default">

                    <transport lock-timeout="60000"/>

                    <replicated-cache name="default" mode="SYNC" batching="true">

                        <locking isolation="REPEATABLE_READ"/>

                    </replicated-cache>

                </cache-container>

                <cache-container name="web" aliases="standard-session-cache" default-cache="dist">

                    <transport lock-timeout="60000"/>

                    <distributed-cache name="dist" virtual-nodes="2" mode="ASYNC" batching="true">

                        <file-store shared="false"/>

                        <state-transfer chunk-size="2500000"/>

                    </distributed-cache>

                    <distributed-cache name="http-session-local-root" virtual-nodes="2" mode="ASYNC" batching="true">

                        <file-store path="ROOT" shared="false"/>

                        <          -transfer chunk-size="2500000"/>

                    </distributed-cache>

                </cache-container>

                <cache-container name="ejb" aliases="sfsb sfsb-cache" default-cache="repl">

                    <transport lock-timeout="60000"/>

                    <replicated-cache name="repl" mode="ASYNC" batching="true">

                        <eviction strategy="LRU"/>

                        <file-store shared="false"/>

                    </replicated-cache>

                    <replicated-cache name="remote-connector-client-mappings" mode="SYNC" batching="true"/>

                    <distributed-cache name="dist" mode="ASYNC" batching="true">

                        <eviction strategy="LRU"/>

                        <file-store shared="false"/>

                    </distributed-cache>

                </cache-container>

                <cache-container name="attask" jndi-name="java:jboss/infinispan/attask" start="EAGER">

                    <transport lock-timeout="60000"/>

                    <distributed-cache name="SESSION" virtual-nodes="2" mode="ASYNC" start="EAGER" batching="true">

                        <eviction strategy="LRU" max-entries="132000"/>

                        <expiration max-idle="28800000" lifespan="-1" interval="60000"/>

                        <state-transfer chunk-size="2500000"/>

                        <file-store shared="false"/>

                    </distributed-cache>

                    <distributed-cache name="RECENT_UPDATES" virtual-nodes="2" mode="ASYNC" start="EAGER" batching="true" owners="1">

                        <eviction strategy="LRU" max-entries="32768"/>

                        <expiration max-idle="-1" lifespan="1800000" interval="60000"/>

                        <state-transfer chunk-size="2500000"/>

                        <file-store shared="false"/>

                    </distributed-cache>

                    <distributed-cache name="AGGREGATE_REPORT" virtual-nodes="2" mode="ASYNC" start="EAGER" batching="true" owners="1">

                        <eviction strategy="LRU" max-entries="32768"/>

                        <expiration max-idle="-1" lifespan="16200000" interval="60000"/>

                        <state-transfer chunk-size="2500000"/>

                        <file-store shared="false"/>

                    </distributed-cache>

                </cache-container>

            </subsystem>

            <subsystem xmlns="urn:jboss:domain:jaxrs:1.0"/>

            <subsystem xmlns="urn:jboss:domain:jca:1.1">

                <archive-validation enabled="true" fail-on-error="true" fail-on-warn="false"/>

                <bean-validation enabled="false"/>

                <default-workmanager>

                    <short-running-threads>

                        <core-threads count="50"/>

                        <queue-length count="50"/>

                        <max-threads count="50"/>

                        <keepalive-time time="10" unit="seconds"/>

                    </short-running-threads>

                    <long-running-threads>

                        <core-threads count="50"/>

                        <queue-length count="50"/>

                        <max-threads count="50"/>

                        <keepalive-time time="10" unit="seconds"/>

                    </long-running-threads>

                </default-workmanager>

                <cached-connection-manager/>

            </subsystem>

            <subsystem xmlns="urn:jboss:domain:jdr:1.0"/>

            <subsystem xmlns="urn:jboss:domain:jgroups:1.1" default-stack="udp">

                <stack name="udp">

                    <transport type="UDP" socket-binding="jgroups-udp" diagnostics-socket-binding="jgroups-diagnostics"/>

                    <protocol type="PING"/>

                    <protocol type="MERGE2"/>

                    <protocol type="FD_SOCK" socket-binding="jgroups-udp-fd"/>

                    <protocol type="FD"/>

                    <protocol type="VERIFY_SUSPECT"/>

                    <protocol type="BARRIER"/>

                    <protocol type="pbcast.NAKACK"/>

                    <protocol type="UNICAST2"/>

                    <protocol type="pbcast.STABLE"/>

                    <protocol type="pbcast.GMS"/>

                    <protocol type="UFC"/>

                    <protocol type="MFC"/>

                    <protocol type="FRAG2"/>

                </stack>

                <stack name="tcp">

                    <transport type="TCP" socket-binding="jgroups-tcp" diagnostics-socket-binding="jgroups-diagnostics"/>

                    <protocol type="MPING" socket-binding="jgroups-mping"/>

                    <protocol type="MERGE2"/>

                    <protocol type="FD_SOCK" socket-binding="jgroups-tcp-fd"/>

                    <protocol type="FD"/>

                    <protocol type="VERIFY_SUSPECT"/>

                    <protocol type="BARRIER"/>

                    <protocol type="pbcast.NAKACK"/>

                    <protocol type="UNICAST2"/>

                    <protocol type="pbcast.STABLE"/>

                    <protocol type="pbcast.GMS"/>

                    <protocol type="UFC"/>

                    <protocol type="MFC"/>

                    <protocol type="FRAG2"/>

                </stack>

            </subsystem>

     

     

    The logs are huge, is there a way to upload a zip file of all the logs?

  • 8. Re: Failed to prepare view exceptions
    dex chen Novice

    We ran into this in our product environment before.

     

    We changed the garbage collection option to use CMP since we have  a large JVM heap  Since then, we have not seen the issue (at least, we do not need to restart once a week as before).

     

    Try the garbage collection tunning if you have not.