2 Replies Latest reply on Oct 18, 2007 9:32 AM by manik

    JBC 1.4.1.SP4 optimistic locking spu usage.

      Hi!
      I have a cluster with 2 load balanced back-end nodes. When using pessimistic locking my cpu usage varies between 5-50% depending on load. I have tried to switch to optimistic locking to improve concurrency, but after doing so my cpu usage skyrocketed to about 90% on both nodes (small load - about 15% on pessimistic locking) and front-ends cant access my back-ends. Is this normal?

      My configuration file for optimistic locking:

      <?xml version="1.0" encoding="UTF-8"?>
      <server>
       <mbean code="org.jboss.cache.TreeCache" name="jboss.cache:service=TreeCache">
      
       <depends>jboss:service=Naming</depends>
       <depends>jboss:service=TransactionManager</depends>
       <attribute name="TransactionManagerLookupClass">org.jboss.cache.GenericTransactionManagerLookup</attribute>
       <attribute name="NodeLockingScheme">OPTIMISTIC</attribute>
       <attribute name="IsolationLevel">READ_COMMITTED</attribute>
       <attribute name="CacheMode">REPL_ASYNC</attribute>
       <attribute name="SyncCommitPhase">false</attribute>
       <attribute name="SyncRollbackPhase">false</attribute>
       <attribute name="UseReplQueue">false</attribute>
       <attribute name="ReplQueueInterval">0</attribute>
       <attribute name="ReplQueueMaxElements">0</attribute>
       <attribute name="EvictionPolicyClass">org.jboss.cache.eviction.LRUPolicy</attribute>
       <attribute name="EvictionPolicyConfig">
       <config>
       <attribute name="wakeUpIntervalSeconds">30</attribute>
       <region name="/_default_">
       <attribute name="maxNodes">50000</attribute>
       <attribute name="timeToLiveSeconds">0</attribute>
       <attribute name="maxAgeSeconds">0</attribute>
       </region>
       <region name="/templates">
       <attribute name="maxNodes">1000</attribute>
       <attribute name="timeToLiveSeconds">0</attribute>
       <attribute name="maxAgeSeconds">0</attribute>
       </region>
       <region name="/post">
       <attribute name="maxNodes">60000</attribute>
       <attribute name="timeToLiveSeconds">0</attribute>
       <attribute name="maxAgeSeconds">0</attribute>
       </region>
       <region name="/comment">
       <attribute name="maxNodes">60000</attribute>
       <attribute name="timeToLiveSeconds">0</attribute>
       <attribute name="maxAgeSeconds">0</attribute>
       </region>
       </config>
       </attribute>
      
       <attribute name="LockParentForChildInsertRemove">true</attribute>
      
       <!--attribute name="FetchInMemoryState">false</attribute-->
       <attribute name="UseRegionBasedMarshalling">true</attribute>
       <attribute name="InactiveOnStartup">true</attribute>
       <attribute name="InitialStateRetrievalTimeout">20000</attribute>
       <attribute name="SyncReplTimeout">20000</attribute>
       <attribute name="LockAcquisitionTimeout">15000</attribute>
      
       <attribute name="ClusterConfig">
       <config>
       <UDP mcast_recv_buf_size="500000" ip_mcast="true" mcast_send_buf_size="32000"
       mcast_port="45501" ucast_recv_buf_size="500000" use_incoming_packet_handler="false"
       mcast_addr="${jgroups.udp.mcast_addr:239.192.0.1}" loopback="false" ucast_send_buf_size="32000" ip_ttl="${jgroups.udp.ip_ttl:5}"/>
       <AUTOCONF/>
       <PING timeout="3000" num_initial_members="2"/>
       <MERGE2 max_interval="10000" min_interval="1000"/>
       <FD_SOCK/>
       <FD timeout="20000" max_tries="5" shun="true"/>
       <VERIFY_SUSPECT timeout="1500"/>
       <pbcast.NAKACK use_mcast_xmit="true" gc_lag="100" retransmit_timeout="1200,2400,4800"/>
       <UNICAST timeout="600,1200,2400"/>
       <pbcast.STABLE desired_avg_gossip="20000"/>
       <FRAG2 frag_size="8192"/>
       <pbcast.GMS print_local_addr="false" join_timeout="5000" join_retry_timeout="2000" shun="true"/>
       <pbcast.STATE_TRANSFER/>
       </config>
       </attribute>
      
       </mbean>
      </server>


      Exceptions:

      2007-09-07 12:11:12,283 WARN [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator_2] TwoPhaseCoordinator.beforeCompletion - failed for com.arjuna.ats.internal.jta.resources.arjunacore.SynchronizationImple@69b7c5
      java.lang.RuntimeException:
      Caused by: org.jboss.cache.optimistic.DataVersioningException: Tx attempted to create /s/sr#11531990 anew. It has already been created since this tx started by another (possibly remote) tx.

      2007-09-07 12:11:12,232 WARN [org.jboss.cache.interceptors.TxInterceptor] Roll back failed encountered
      java.lang.IllegalStateException: BaseTransaction.rollback - [com.arjuna.ats.internal.jta.transaction.arjunacore.notx] [com.arjuna.ats.internal.jta.transaction.arjunacore.notx] no transaction!

      2007-09-07 11:58:53,790 WARN [org.jboss.cache.interceptors.TxInterceptor] Rolling back, exception encountered
      javax.transaction.RollbackException: [com.arjuna.ats.internal.jta.transaction.arjunacore.commitwhenaborted] [com.arjuna.ats.internal.jta.transaction.arjunacore.commitwhenaborted] Can't commit because the transaction is in aborted state
      Caused by: java.lang.RuntimeException:
       at org.jboss.cache.interceptors.TxInterceptor$LocalSynchronizationHandler.beforeCompletion(Unknown Source)
       at org.jboss.cache.interceptors.OrderedSynchronizationHandler.beforeCompletion(Unknown Source)
       at com.arjuna.ats.internal.jta.resources.arjunacore.SynchronizationImple.beforeCompletion(SynchronizationImple.java:114)
       at com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.beforeCompletion(TwoPhaseCoordinator.java:247)
       at com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.end(TwoPhaseCoordinator.java:86)
       at com.arjuna.ats.arjuna.AtomicAction.commit(AtomicAction.java:177)
       at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.commitAndDisassociate(TransactionImple.java:1382)
       ... 68 more
      Caused by: org.jboss.cache.optimistic.DataVersioningException: Tx attempted to create /s/sr#11719693 anew. It has already been created since this tx started by another (possibly remote) tx.
       at org.jboss.cache.interceptors.OptimisticValidatorInterceptor.simpleValidate(Unknown Source)
       at org.jboss.cache.interceptors.OptimisticValidatorInterceptor.validateNodes(Unknown Source)
       at org.jboss.cache.interceptors.OptimisticValidatorInterceptor.invoke(Unknown Source)
       at org.jboss.cache.interceptors.Interceptor.invoke(Unknown Source)
       at org.jboss.cache.interceptors.OptimisticLockingInterceptor.invoke(Unknown Source)
       at org.jboss.cache.interceptors.Interceptor.invoke(Unknown Source)
       at org.jboss.cache.interceptors.OptimisticReplicationInterceptor.invoke(Unknown Source)
       at org.jboss.cache.interceptors.Interceptor.invoke(Unknown Source)
       at org.jboss.cache.interceptors.TxInterceptor.runPreparePhase(Unknown Source)
       ... 75 more