13 Replies Latest reply on Oct 29, 2012 2:02 AM by Brian Wallis

    Hanging in hibernate search

    Brian Wallis Master

      Same code as in the the discussion https://community.jboss.org/thread/211707?tstart=0 only configured with JDBC cache loaders instead of file based cache loaders to avoid the too many open files problem. Now I get a hang after creating a lot of nodes (something like 8000 - 12000 or so) with the main thread stuck waiting on a future result after a call to session.save(). JDK is 1.6.0_37 on MacOSX 10.6.8. I've built the test with Infinispan 5.1.2.FINAL and 5.1.6.FINAL but it hangs with either after running for a while. The modeshape version is 3.0.0.CR2 (CR3 still doesn't seem to be available on repository.jboss.org)

       

      First thing, have I got the repository and cache configurations correct? I had to experiment a bit to get it working and may have mucked something up.

       

      I've attached the code and configuration as a maven project.

       

       

      {code}

      "main" prio=5 tid=101800800 nid=0x100501000 waiting on condition [1004ff000]

         java.lang.Thread.State: WAITING (parking)

                at sun.misc.Unsafe.park(Native Method)

                - parking to wait for  <7f32c8148> (a java.util.concurrent.FutureTask$Sync)

                at java.util.concurrent.locks.LockSupport.park(LockSupport.java:156)

                at java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:811)

                at java.util.concurrent.locks.AbstractQueuedSynchronizer.doAcquireSharedInterruptibly(AbstractQueuedSynchronizer.java:969)

                at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireSharedInterruptibly(AbstractQueuedSynchronizer.java:1281)

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

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

                at org.hibernate.search.backend.impl.lucene.LuceneBackendQueueProcessor.applyWork(LuceneBackendQueueProcessor.java:97)

                at org.hibernate.search.indexes.impl.DirectoryBasedIndexManager.performOperations(DirectoryBasedIndexManager.java:127)

                at org.hibernate.search.backend.impl.WorkQueuePerIndexSplitter.commitOperations(WorkQueuePerIndexSplitter.java:61)

                at org.hibernate.search.backend.impl.BatchedQueueingProcessor.performWorks(BatchedQueueingProcessor.java:96)

                at org.hibernate.search.backend.impl.PostTransactionWorkQueueSynchronization.afterCompletion(PostTransactionWorkQueueSynchronization.java:99)

                at org.infinispan.transaction.tm.DummyTransaction.notifyAfterCompletion(DummyTransaction.java:272)

                at org.infinispan.transaction.tm.DummyTransaction.runCommitTx(DummyTransaction.java:321)

                at org.infinispan.transaction.tm.DummyTransaction.commit(DummyTransaction.java:90)

                at org.infinispan.transaction.tm.DummyBaseTransactionManager.commit(DummyBaseTransactionManager.java:100)

                at org.modeshape.jcr.txn.Transactions$SimpleTransaction.commit(Transactions.java:230)

                at org.modeshape.jcr.cache.document.WritableSessionCache.save(WritableSessionCache.java:512)

                at org.modeshape.jcr.JcrSession.save(JcrSession.java:917)

                at au.com.infomedix.mode_1678.LeakTest.create(LeakTest.java:194)

                at au.com.infomedix.mode_1678.LeakTest.createAndQuery(LeakTest.java:90)

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

                at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:44)

                at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:15)

                at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:41)

                at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:20)

                at org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:28)

                at org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:31)

                at org.junit.runners.BlockJUnit4ClassRunner.runNotIgnored(BlockJUnit4ClassRunner.java:79)

                at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:71)

                at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:49)

                at org.junit.runners.ParentRunner$3.run(ParentRunner.java:193)

                at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:52)

                at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:191)

                at org.junit.runners.ParentRunner.access$000(ParentRunner.java:42)

                at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:184)

                at org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:28)

                at org.junit.runners.ParentRunner.run(ParentRunner.java:236)

                at org.eclipse.jdt.internal.junit4.runner.JUnit4TestReference.run(JUnit4TestReference.java:50)

                at org.eclipse.jdt.internal.junit.runner.TestExecution.run(TestExecution.java:38)

                at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.runTests(RemoteTestRunner.java:467)

                at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.runTests(RemoteTestRunner.java:683)

                at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.run(RemoteTestRunner.java:390)

                at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.main(RemoteTestRunner.java:197)

      {code}

        • 1. Re: Hanging in hibernate search
          Ivan Vasyliev Newbie

          Hi,

          I saw similar stacktrace before:

          http://stackoverflow.com/questions/1393139/deadlock-in-threadpoolexecutor

           

          Can you try on other system? Eg linux and jdk7?

          • 2. Re: Hanging in hibernate search
            Brian Wallis Master

            Tried on a linux system (note, the pom has a typo, the hibernate-search-infinispan version should be 4.1.1.Final, not 4.1.1.FINAL, Mac has a case insensitive filesystem)

             

             

            {code}

            udr@bw-test:~/1678-Test> uname -a

            Linux bw-test 2.6.37.1-1.2-desktop #1 SMP PREEMPT 2011-02-21 10:34:10 +0100 x86_64 x86_64 x86_64 GNU/Linux

            udr@bw-test:~/1678-Test> cat /etc/issue

            Welcome to openSUSE 11.4 "Celadon" - Kernel \r (\l).

               

            udr@bw-test:~/1678-Test> java -version

            java version "1.6.0_34"

            Java(TM) SE Runtime Environment (build 1.6.0_34-b04)

            Java HotSpot(TM) 64-Bit Server VM (build 20.9-b04, mixed mode)

            {code}

             

            exactly the same result. Hangs on the Future result during the 6th iteration after creating about 11800 nodes. As I said, I cannot get this to fail with the cache loaders configured for a filesystem store due to the too many open files problem.

            • 3. Re: Hanging in hibernate search
              Brian Wallis Master

              I tried it with java 1.7.0_09 on the linux system with the same result.

               

              Now that I have run it a few times on both the mac and linux I have noticed that the stop point is not random. It stops during 6th iteration (after the message "Start create cycle 5") on the linux system and there are 11826 entries in the table for the node storage and it stops during the 7th iteration on the mac and there are 13432 entries in the table for the node storage (query_datarepository).

               

              It is almost as if something has filled up. Some system resource that is not being released?

               

              (p.s. As far as the thread dump from java is concerned, there isn't an actual detectable deadlock)

              • 4. Re: Hanging in hibernate search
                Randall Hauch Master

                Tried on a linux system (note, the pom has a typo, the hibernate-search-infinispan version should be 4.1.1.Final, not 4.1.1.FINAL

                Brian, where do you see "4.1.1.FINAL"? Our parent POM specifies the version of Hibernate Search artifacts, and it says "4.1.1.Final". In fact, I can't find any use of "4.1.1.FINAL". Are you sure you're not overwriting the version in your POM?

                • 5. Re: Hanging in hibernate search
                  Brian Wallis Master

                  Sorry, that was my pom in the attached code that has the typo, not the modeshape pom.

                  • 6. Re: Hanging in hibernate search
                    Brian Wallis Master

                    I was looking at the issue last night using the debugger and had the code suspended for a period of time and then continued. I didn't get very far in understanding what was actually happening but noticed that the suspend/wait/resume caused the failure to happen far sooner, before the end of the first iteration (before 1606 nodes created).

                    • 7. Re: Hanging in hibernate search
                      Brian Wallis Master

                      Tried a simpler testcase for this

                       

                      {code}

                       

                          @Test

                          public void sessionWaitSaveTest()

                                                   throws Exception

                          {

                              Session session = null;

                       

                              try

                              {

                                  session = repository.login();

                                  session.save();

                                  session.logout();

                       

                                  log.info("Sleep for 15 minutes");

                                  Thread.sleep(15 * 60 * 1000);

                                  log.info("Awake now...");

                       

                                  session = repository.login();

                       

                                  log.info("Add testRoot node");

                       

                                  Node testRoot = session.getRootNode().addNode("testRoot", "nt:folder");

                       

                                  log.info("Save Session");

                                  session.save();

                                  log.info("Saved Session");

                              }

                              finally

                              {

                                  if(session != null)

                                  {

                                      session.logout();

                                  }

                              }

                          }

                      {code}

                       

                      This hangs in the second session.save() call at the same place as included in the original post. I've tried a configuration with in memory data and indexes and it runs fine, it is only when I use the JDBC cache loaders. If you don't do the 15 minutes sleep the test succeeds. If you sleep for a short while (up to 10 or so minutes I think) then it also still completes but set it to 15 minutes and it hangs as previously described.

                       

                      I've attached an updated zip of the maven project with the test case and configuration. I've tried this with both a dummy transaction manager and with the arjuna standalone one but same result. 

                      • 8. Re: Hanging in hibernate search
                        Horia Chiorean Master

                        Did you try, by any chance, with H2 in mem ? I'm curious whether it has to do with disk storage or generic JDBC.

                        • 9. Re: Hanging in hibernate search
                          Horia Chiorean Master

                          Something else: looking at the example, the index metadata, index data and jcr data are all stored in the same table: jcr_data, which isn't...ideal

                          • 10. Re: Hanging in hibernate search
                            Brian Wallis Master

                            No, three tables are created in the one schema, jcr_data

                             

                            jcr_data=# \d

                                           List of relations

                            Schema |         Name         | Type  | Owner

                            --------+----------------------+-------+-------

                            public | query_datarepository | table | jcr

                            public | query_indexdata      | table | jcr

                            public | query_indexmetadata  | table | jcr

                            (3 rows)

                             

                            so I think that should be OK.

                             

                            I haven't tried it with H2, I'll give it a go.

                            • 11. Re: Hanging in hibernate search
                              Horia Chiorean Master

                              I have investigated this a bit (btw, the test case is excelent) and this is what I can tell so far:

                               

                              - the problem can be reproduced just by having the indexData persisted in a JDBC cache store (it isn't required to have the others configured via JDBC cache loaders)

                              - the indefinite wait is caused, in effect, by the starvation of the jdbc connection pool (this can be seen from the Thread Dumps)

                              - both Hibernate Search & Infinispan JdbcBinaryCacheStore.purgeInternal open db connections

                               

                              I haven't looked at various cache configuration options yet, to see if there is a workaround

                               

                              All in all, I agree that this is a problem, however, imo this an Infinispan/Hibernate Search problem at the core, rather than ModeShape, or the way in which ModeShape uses those subsystems.

                              • 12. Re: Hanging in hibernate search
                                Horia Chiorean Master

                                In all earnest, the test does expose this https://issues.jboss.org/browse/MODE-1692 issue.

                                 

                                What this means for the test case, is that the "async" mode is ignored and everything is sync. However, even with async passed correctly, the test will now fail in tearDown, because the ModeShape engine will not be shutdown in 10 seconds as the indexing threads are still active & waiting.

                                • 13. Re: Hanging in hibernate search
                                  Brian Wallis Master

                                  Should I create a modeshape ticket for this issue?