9 Replies Latest reply on Mar 8, 2006 11:06 AM by jaikiran pai

    JBossCache-1.2.4 with Hibernate-3.1.2, IdentityLock ERROR lo

    jaikiran pai Master

      Hi,
      We *were* using Hibernate-2.1.3 and JBossCache-1.2 with JBoss-3.2.3. Because of PESSIMISTIC locking issues, we are in the process of upgrading to Hibernate-3.1.2 and JBossCache-1.2.4(we are still using PESSIMISTIC approach). We are currently seeing a lot of logs as below:

      15:14:05,296 WARN [LRUAlgorithm] eviction timed out. Will retry later.
      15:14:06,796 ERROR [IdentityLock] write lock for /com/dbdata/core/hibernateobject/SmSegmentPlanRelationship/smParentSegments/com.dbdata.core.hibernateobject.SmSegmentPlanRelationship.smParentSegments#com.dbdata.core.hibernateobject.SmSegmentPlanRelationshipId[segmentPlanId=56203, segmentPlanVersionId=1, relationshipId=6] could not be acquired a
      fter 1500 ms. Locks: Read lock owners: {GlobalTransaction:<null>:357=java.lang.Object@b2e5d0}
      Write lock owner: null
      (caller=Thread[Thread-35,5,jboss], lock info: read owners=[GlobalTransaction:<null>:357] (activeReaders=1, activeWriter=null, waitingReaders=0, waitingWriters=0, waitingUpgrader=0))
      15:14:06,796 WARN [LRUAlgorithm] eviction timed out. Will retry later.
      15:14:08,296 ERROR [IdentityLock] write lock for /com/dbdata/core/hibernateobject/SmSegmentPlanRelationship/smPickBestQualifications/com.dbdata.core.hibernateobject.SmSegmentPlanRelationship.smPickBestQualifications#com.dbdata.core.hibernateobject.SmSegmentPlanRelationshipId[segmentPlanId=56203, segmentPlanVersionId=1, relationshipId=5] could n
      ot be acquired after 1500 ms. Locks: Read lock owners: {GlobalTransaction:<null>:357=java.lang.Object@b2e5d0}
      Write lock owner: null
      (caller=Thread[Thread-35,5,jboss], lock info: read owners=[GlobalTransaction:<null>:357] (activeReaders=1, activeWriter=null, waitingReaders=0, waitingWriters=0, waitingUpgrader=0))
      15:14:08,296 WARN [LRUAlgorithm] eviction timed out. Will retry later.
      15:14:09,796 ERROR [IdentityLock] write lock for /com/dbdata/core/hibernateobject/SmSegmentPlanRelationship/smLogicalSegmentRuns/com.dbdata.core.hibernateobject.SmSegmentPlanRelationship.smLogicalSegmentRuns#com.dbdata.core.hibernateobject.SmSegmentPlanRelationshipId[segmentPlanId=56203, segmentPlanVersionId=1, relationshipId=5] could not be ac
      quired after 1500 ms. Locks: Read lock owners: {GlobalTransaction:<null>:357=java.lang.Object@b2e5d0}
      Write lock owner: null
      (caller=Thread[Thread-35,5,jboss], lock info: read owners=[GlobalTransaction:<null>:357] (activeReaders=1, activeWriter=null, waitingReaders=0, waitingWriters=0, waitingUpgrader=0))
      15:14:09,796 WARN [LRUAlgorithm] eviction timed out. Will retry later.
      15:14:11,296 ERROR [IdentityLock] write lock for /com/dbdata/core/hibernateobject/SmSegmentPlanRelationship/smChildSegments/com.dbdata.core.hibernateobject.SmSegmentPlanRelationship.smChildSegments#com.dbdata.core.hibernateobject.SmSegmentPlanRelationshipId[segmentPlanId=56203, segmentPlanVersionId=1, relationshipId=5] could not be acquired aft
      er 1500 ms. Locks: Read lock owners: {GlobalTransaction:<null>:357=java.lang.Object@b2e5d0}
      Write lock owner: null
      (caller=Thread[Thread-35,5,jboss], lock info: read owners=[GlobalTransaction:<null>:357] (activeReaders=1, activeWriter=null, waitingReaders=0, waitingWriters=0, waitingUpgrader=0))
      15:14:11,311 WARN [LRUAlgorithm] eviction timed out. Will retry later.
      15:14:12,811 ERROR [IdentityLock] write lock for /com/dbdata/core/hibernateobject/SmSegmentPlanRelationship/smParentSegments/com.dbdata.core.hibernateobject.SmSegmentPlanRelationship.smParentSegments#com.dbdata.core.hibernateobject.SmSegmentPlanRelationshipId[segmentPlanId=56203, segmentPlanVersionId=1, relationshipId=5] could not be acquired a
      fter 1500 ms. Locks: Read lock owners: {GlobalTransaction:<null>:357=java.lang.Object@b2e5d0}
      Write lock owner: null
      (caller=Thread[Thread-35,5,jboss], lock info: read owners=[GlobalTransaction:<null>:357] (activeReaders=1, activeWriter=null, waitingReaders=0, waitingWriters=0, waitingUpgrader=0))
      15:14:12,811 WARN [LRUAlgorithm] eviction timed out. Will retry later.


      Our LockAcquisitionTimeout is 1500ms in treecache.xml.
      Can these logs be ignored? Or are they indicating any serious issues?

      Thank you.


        • 1. Re: JBossCache-1.2.4 with Hibernate-3.1.2, IdentityLock ERRO
          Ben Wang Master

          Looks like the eviction thread tried to evict/remove the nodes but it times out because someone is holding the read lock for more than 15 secs.

          So I'd say this is an anomaly. Is this re-producible?

          • 2. Re: JBossCache-1.2.4 with Hibernate-3.1.2, IdentityLock ERRO
            jaikiran pai Master

             

            "ben.wang@jboss.com" wrote:
            Is this re-producible?


            Very much. Our server log is completely filled with these logs.


            "ben.wang@jboss.com" wrote:
            Looks like the eviction thread tried to evict/remove the nodes but it times out because someone is holding the read lock for more than 15 secs.


            I believe, you meant 1.5 secs and not 15 sec, since my LockAcquisitionTimeout is 1500ms, right?

            • 3. Re: JBossCache-1.2.4 with Hibernate-3.1.2, IdentityLock ERRO
              jaikiran pai Master

               

              Looks like the eviction thread tried to evict/remove the nodes but it times out because someone is holding the read lock


              One question, if the node is being used by someone, then why is this node considered as a candidate for eviction, by the LRU algorithm?

              Also, these logs are flooding the server log. Do you think there is some major issue involved here?

              • 5. Re: JBossCache-1.2.4 with Hibernate-3.1.2, IdentityLock ERRO
                Ben Wang Master

                Sorry. Here is my additiona comments:

                1. So you turn on eviction specifically on your own? Can you post the xml config then?

                2. Why do you use such a short lock timeout value, just curious. The default is 15sec actually. If it is just 1.5 second, then it is hard to say whether there is definite problem or not.

                -Ben

                • 6. Re: JBossCache-1.2.4 with Hibernate-3.1.2, IdentityLock ERRO
                  jaikiran pai Master

                   

                  2. Why do you use such a short lock timeout value, just curious. The default is 15sec actually.

                  Sorry, that's my mistake. I was under the impression that the default value was 1.5 sec. I will change this to 15 sec and try out the application.

                  Can you post the xml config then?

                  Here's the treecahe.xml that we are using:

                  <?xml version="1.0" encoding="UTF-8"?>
                  
                  <!-- ===================================================================== -->
                  <!-- -->
                  <!-- Sample TreeCache Service Configuration -->
                  <!-- -->
                  <!-- ===================================================================== -->
                  
                  <server>
                  
                   <classpath codebase="./lib" archives="jboss-cache.jar, jgroups.jar"/>
                  
                  
                   <!-- ==================================================================== -->
                   <!-- Defines TreeCache configuration -->
                   <!-- ==================================================================== -->
                  
                   <mbean code="org.jboss.cache.TreeCache" name="jboss.cache:service=TreeCache">
                  
                   <depends>jboss:service=Naming</depends>
                   <depends>jboss:service=TransactionManager</depends>
                  
                   <!--
                   Configure the TransactionManager
                   -->
                   <attribute name="TransactionManagerLookupClass">org.jboss.cache.GenericTransactionManagerLookup</attribute>
                  
                   <!--
                   Node locking scheme:
                   OPTIMISTIC
                   PESSIMISTIC (default)
                   -->
                   <attribute name="NodeLockingScheme">PESSIMISTIC</attribute>
                  
                   <!--
                   Isolation level : SERIALIZABLE
                   REPEATABLE_READ (default)
                   READ_COMMITTED
                   READ_UNCOMMITTED
                   NONE
                   -->
                   <attribute name="IsolationLevel">REPEATABLE_READ</attribute>
                  
                   <!--
                   Valid modes are LOCAL, REPL_ASYNC and REPL_SYNC
                   -->
                   <attribute name="CacheMode">LOCAL</attribute>
                  
                   <!--
                   Just used for async repl: use a replication queue
                   -->
                   <attribute name="UseReplQueue">false</attribute>
                  
                   <!--
                   Replication interval for replication queue (in ms)
                   -->
                   <attribute name="ReplQueueInterval">0</attribute>
                  
                   <!--
                   Max number of elements which trigger replication
                   -->
                   <attribute name="ReplQueueMaxElements">0</attribute>
                  
                   <!-- Name of cluster. Needs to be the same for all clusters, in order
                   to find each other
                   -->
                   <attribute name="ClusterName">TAP-ApplicationCache</attribute>
                  
                   <!-- JGroups protocol stack properties. Can also be a URL,
                   e.g. file:/home/bela/default.xml
                   <attribute name="ClusterProperties"></attribute>
                   -->
                  
                   <attribute name="ClusterConfig">
                   <config>
                   <!-- UDP: if you have a multihomed machine,
                   set the bind_addr attribute to the appropriate NIC IP address -->
                   <!-- UDP: On Windows machines, because of the media sense feature
                   being broken with multicast (even after disabling media sense)
                   set the loopback attribute to true -->
                   <UDP mcast_addr="228.1.2.3" mcast_port="48866"
                   ip_ttl="64" ip_mcast="true"
                   mcast_send_buf_size="150000" mcast_recv_buf_size="80000"
                   ucast_send_buf_size="150000" ucast_recv_buf_size="80000"
                   loopback="false"/>
                   <PING timeout="2000" num_initial_members="3"
                   up_thread="false" down_thread="false"/>
                   <MERGE2 min_interval="10000" max_interval="20000"/>
                   <!-- <FD shun="true" up_thread="true" down_thread="true" />-->
                   <FD_SOCK/>
                   <VERIFY_SUSPECT timeout="1500"
                   up_thread="false" down_thread="false"/>
                   <pbcast.NAKACK gc_lag="50" retransmit_timeout="600,1200,2400,4800"
                   max_xmit_size="8192" up_thread="false" down_thread="false"/>
                   <UNICAST timeout="600,1200,2400" window_size="100" min_threshold="10"
                   down_thread="false"/>
                   <pbcast.STABLE desired_avg_gossip="20000"
                   up_thread="false" down_thread="false"/>
                   <FRAG frag_size="8192"
                   down_thread="false" up_thread="false"/>
                   <pbcast.GMS join_timeout="5000" join_retry_timeout="2000"
                   shun="true" print_local_addr="true"/>
                   <pbcast.STATE_TRANSFER up_thread="true" down_thread="true"/>
                   </config>
                   </attribute>
                  
                   <!--
                   Whether or not to fetch state on joining a cluster
                   -->
                   <attribute name="FetchStateOnStartup">true</attribute>
                  
                   <!--
                   The max amount of time (in milliseconds) we wait until the
                   initial state (ie. the contents of the cache) are retrieved from
                   existing members in a clustered environment
                   -->
                   <attribute name="InitialStateRetrievalTimeout">5000</attribute>
                  
                   <!--
                   Number of milliseconds to wait until all responses for a
                   synchronous call have been received.
                   -->
                   <attribute name="SyncReplTimeout">10000</attribute>
                  
                   <!-- Max number of milliseconds to wait for a lock acquisition -->
                   <attribute name="LockAcquisitionTimeout">1500</attribute>
                  
                  
                   <!-- Name of the eviction policy class. -->
                   <attribute name="EvictionPolicyClass">org.jboss.cache.eviction.LRUPolicy</attribute>
                   <!-- Specific eviction policy configurations. This is LRU -->
                   <attribute name="EvictionPolicyConfig">
                   <config>
                   <attribute name="wakeUpIntervalSeconds">5</attribute>
                   <!-- Cache wide default -->
                   <region name="/_default_">
                   <attribute name="maxNodes">5000</attribute>
                   <attribute name="timeToIdleSeconds">1000</attribute>
                   </region>
                   <region name="/com/teradata/tap/system/folder/FolderService">
                   <attribute name="maxNodes">5000</attribute>
                   <attribute name="timeToIdleSeconds">600</attribute>
                   </region>
                   </config>
                   </attribute>
                   </mbean>
                  
                  
                   <!-- Uncomment to get a graphical view of the TreeCache MBean above -->
                   <!-- <mbean code="org.jboss.cache.TreeCacheView" name="jboss.cache:service=TreeCacheView">-->
                   <!-- <depends>jboss.cache:service=TreeCache</depends>-->
                   <!-- <attribute name="CacheService">jboss.cache:service=TreeCache</attribute>-->
                   <!-- </mbean>-->
                  
                  
                  </server>


                  So you turn on eviction specifically on your own?

                  We have specified the :
                  <attribute name="EvictionPolicyClass">org.jboss.cache.eviction.LRUPolicy</attribute>

                  in the treecache.xml. Not doing anything else on our own, relating to eviction.





                  • 7. Re: JBossCache-1.2.4 with Hibernate-3.1.2, IdentityLock ERRO
                    Ben Wang Master

                    well, you actually also created a Region under com/teradata. But it seems they all fall under __default__.

                    • 8. Re: JBossCache-1.2.4 with Hibernate-3.1.2, IdentityLock ERRO
                      jaikiran pai Master

                      Here's the latest update. After changing the LockAcquisitionTimeoutValue to 15 seconds, this ERROR log has stopped.

                      well, you actually also created a Region under com/teradata. But it seems they all fall under __default__.


                      I guess, we will have to create a separate region for the nodes that we were seeing in the earlier error logs, so that they dont fall under __default__