13 Replies Latest reply on Aug 11, 2004 12:45 AM by Ben Wang

    TreeCache deadlock

    rchristy Newbie

      I have an application that is using JBoss 3.2.4RC2 with Hibernate with 2.1.2, configured using TreeCache. I have a test that writes/updates and than deletes objects. That seems to complete successfully, but any time after that we attempt to evict the cache (I have an MBean that can evict on demand to clear any cache) we get the following exception. Can anyone explain why this would happening? Am I forgetting to do something to clear this lock?

      Thanks,

      Rich

      Caused by: org.jboss.cache.lock.TimeoutException: IdentityLock.acquireWriteLock(): lock could not be acquired after 10000 ms. Lock map ownership Read lock owners: [:2]
      Write lock owner: null

      at org.jboss.cache.lock.IdentityLock.acquireWriteLock(IdentityLock.java:151)
      at org.jboss.cache.Node.acquireWriteLock(Node.java:412)
      at org.jboss.cache.Node.acquire(Node.java:381)
      at org.jboss.cache.TreeCache.findNode(TreeCache.java:2851)
      at org.jboss.cache.TreeCache._remove(TreeCache.java:1805)
      at org.jboss.cache.TreeCache._remove(TreeCache.java:1782)
      at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
      at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
      at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
      at java.lang.reflect.Method.invoke(Method.java:324)
      at org.jgroups.blocks.MethodCall.invoke(MethodCall.java:395)
      at org.jboss.cache.TreeCache.invokeMethod(TreeCache.java:2640)
      at org.jboss.cache.TreeCache.remove(TreeCache.java:1183)
      at net.sf.hibernate.cache.TreeCache.clear(TreeCache.java:85)

        • 1. Re: TreeCache deadlock
          Ben Wang Master

          Rich,

          Can you send me a sample log file with "org.jboss.cache" category and "DEBUG" level tracing from log4j.xml? In there is a detailed log for lock information.

          Thanks,

          -Ben

          • 2. Re: TreeCache deadlock
            rchristy63 Newbie

            Ben,

            I have your trace, but the file is too big to cut and paste into here and I can't see how to attach a file. Do you want me to just email to you?

            Rich

            • 3. Re: TreeCache deadlock
              Ben Wang Master

              Yes, please email it me at ben.wang@jboss.com.

              Thanks,

              -ben

              • 4. Re: TreeCache deadlock
                chucklan Newbie

                I also encountered a deadlock. I'm instantiating two TreeCache instances in my application.
                One through Hibernate for the second level cache, and the other for read cache. When I call cache.put(fqn, key, val) for the read cache, I'm getting the following:

                (note, normally there are no TimeoutExceptions, except when we call put concurrently through two separate threads.)

                [17:17:11.480] Thread[thread-pool-38,5,main]before cache put for daily
                17:17:11,480 DEBUG [TreeCache] _remove(<clan:3575>:11, "/SWSOCCER/scoreLists", DAILY)
                17:17:11,480 DEBUG [IdentityLock] acquireReadLock(): caller already owns lock.
                17:17:11,480 DEBUG [Node] acquired RL: fqn=/SWSOCCER, owner=<clan:3575>:11, lock=org.jboss.cache.lock.IdentityLock@e98ccf
                17:17:11,480 DEBUG [IdentityLock] acquireWriteLock(): upgrade lock
                17:17:11,480 DEBUG [Node] acquired WL: fqn=/SWSOCCER/scoreLists, owner=<clan:3575>:10, lock=org.jboss.cache.lock.IdentityLock@11b9cc4
                17:17:11,480 DEBUG [IdentityLock] release(): lock map owner <clan:3575>:11 not found. Could have been released.
                17:17:11,480 DEBUG [TreeCache] _put(<clan:3575>:10, "/SWSOCCER/scoreLists", DAILY, com.asw.highscore.model.ScoreList@a7c257)
                17:17:11,480 DEBUG [TreeCache] rollback(): called to rollback cache
                17:17:11,480 DEBUG [IdentityLock] acquireReadLock(): caller already owns lock.
                17:17:11,480 DEBUG [TreeCache] rollback(): releasing lock org.jboss.cache.lock.IdentityLock@11b9cc4
                17:17:11,480 DEBUG [Node] acquired RL: fqn=/SWSOCCER, owner=<clan:3575>:10, lock=org.jboss.cache.lock.IdentityLock@e98ccf
                17:17:11,480 DEBUG [IdentityLock] release(): lock map owner <clan:3575>:11 not found. Could have been released.
                17:17:11,480 DEBUG [IdentityLock] acquireWriteLock(): caller already owns lock.
                17:17:11,480 DEBUG [TreeCache] rollback(): releasing lock org.jboss.cache.lock.IdentityLock@e98ccf
                17:17:11,480 DEBUG [Node] acquired WL: fqn=/SWSOCCER/scoreLists, owner=<clan:3575>:10, lock=org.jboss.cache.lock.IdentityLock@11b9cc4
                17:17:11,480 DEBUG [IdentityLock] release(): lock map owner <clan:3575>:11 not found. Could have been released.
                [17:17:11.480] IdentityLock.acquireWriteLock(): upgrade lock could not [17:17:11.480] IdentityLock.acquireWriteLock(): upgrade lock could not be acquired after 15000 ms. Lock map ownership Read lock owners: [<clan:3575>:10]
                [17:17:11.480] Write lock owner: null
                


                Both caches are configured to be transactioanal, and replicated. Txn isolation level is at the default of REPEATABLE_READ.

                Can you shed some light on this?

                Thanks,

                Chuck

                • 5. Re: TreeCache deadlock
                  Ben Wang Master

                  Chuck,

                  From the log, acquireWriteLock timeout after 15 secs because the node lock is currently owned by a read lock [<clan:3575>:10]. Right before the timeout message, I can see the read lock owner [<clan:3575>:10] is still active.

                  Is this the log file the read cache only? Can you again send me the full log file to ben.wang@jboss.com.

                  FYI, when Rich sent me the log file, I discovered the reason that cache never released the lock was because after a transaction already committed exception, there was still more activities going on. But later on, transaction manager never issues a commit to cache. As a result, cache would hold on to the lock like forever.

                  Thanks,

                  -Ben

                  • 6. Re: TreeCache deadlock
                    chucklan Newbie

                    The funny thing was that the timeout exception was thrown instantly, rather than after 15 seconds. Could it have to do with the fact that the cache is configured async?

                    I'm obtaining the txn through hibernate's Session object. And I do a rollback immediately when I catch an exception. Is there any problem with doing it this way?

                    I'll send you another log after I get back to work. Happy 4th of July!

                    Thanks,

                    Chuck

                    • 7. Re: TreeCache deadlock
                      rchristy Newbie

                      Ben,

                      Any luck with a fix for this problem yet?

                      Rich

                      • 8. Re: TreeCache deadlock
                        Ben Wang Master

                        Rich, not yet. I am still waiting for Chuck's log file. But can you also send me your code snippet calling Hibernate apis? :-)

                        Chuck, when you send me the log file, can you also give me a snippet for your code as well? E.g., how you call Hibernate and then do your own rollback. And what happens after the rollback?

                        Thanks,

                        -Ben

                        • 9. Re: TreeCache deadlock
                          rchristy Newbie

                          Ben,

                          Here is the code segment I was using to get the exception
                          using the Hibernate API. The scenario is to create a new
                          object using this code and than update that object again using
                          the same code segment within a JBoss CMT. The exception
                          will happen on the session.flush() of the update. Is this enough
                          of a code segment for you?

                          Thanks,

                          Rich

                          Session session = null;
                          try {
                          Context context = new InitialContext();
                          SessionFactory sessionFactory = (SessionFactory)context.lookup("java:/hibernate/HibernateFactory");
                          session = sessionFactory.openSession();

                          Object object = session.saveOrUpdateCopy(mappedObj);

                          session.flush();

                          } catch (Exception e) {
                          e.printStackTrace();
                          } finally {
                          session.close(session);
                          }

                          • 10. Re: TreeCache deadlock
                            Ben Wang Master

                            Hi, Rich,

                            Would you mind to send the whole test file to me through email? ben.wang@jboss.com.

                            You and Chuck may experience different problems, unfortunately.

                            Thanks,

                            -Ben

                            • 11. Re: TreeCache deadlock
                              Ben Wang Master

                              Just let you know that we have solved Chuck's problem. Looks like it is different from the one that Rich has.

                              I have created a sf bug #992297. Herfe is description:

                              Currently when transaction isolation level is set to
                              REPEATABLE, it uses read write lock with upgrade.
                              However, when there are multiple upgrade threads
                              request, only the first thread is allowed to wait. The
                              rest of return right away and throw a timeout exception.

                              Application developer should catch this exception and
                              then re-try. Problem is we should provde a more
                              explicit exception, possibly
                              TooManyUpgradeWaiterException for this specific case.

                              Thanks,

                              -ben

                              • 12. Re: TreeCache deadlock
                                rchristy Newbie

                                Hi Ben,

                                I missed your posting on the 8th, do you still need anything else from me?

                                Rich

                                • 13. Re: TreeCache deadlock
                                  Ben Wang Master

                                  Rich,

                                  I have worked with Chritian Bauer to troubleshoot this problem. Unfortunately, we can't reproduce it at this moment. So we are stuck.

                                  -Ben