6 Replies Latest reply on May 5, 2015 7:34 PM by sannegrinovero

    ProtobufValueWrapper, Hibernate Search and Slow Query performance

    prashant.thakur
    prashant.thakur May 2, 2015 10:06 AM

      We are doing some benchmarking related to query performance of Infinispan in compatibiltiy mode.

      Might not be the one giving the best performance number as radargun would give but the tests are more centered around how our applications would interact.

      We have just one Node Holding Infinispan Data so network operations involved except for client in another box time to retreive data through hotrod.

       

      When I look at number of threads Hibernate threads are bloating up and CPU utlization is approx at 90% . I am basically unable to understand relation between Hibernate Search and ProtobufValueWrapper as we are in compatibility mode why is this wrapper coming into picture unless the data is being passed across to the remote client. If its remote client then it should only be ProtobufValueWrapper and not Hibernate Search if my understand is correct which obviously is confused .

       

      Can you please explain this relation so that we can optimize somehow our query performance or suggest how it can be tuned ?

      Coming to second part when we compare getwithVersion with Query results the difference is huge for same data set.


      The performance with Get done on key is ~ 83 k and when same is used in Query it gives around 5k performance with 50 client threads.


      This is approx 16x slower. Can you please suggest where we might be going wrong in using query module or this is an expected behaviour while using query module ?

      The CPU utilization is also very high than expected.


      We are attaching some JConsole Screenshots for reference.


      There are 40 Server side threads on 16 core machine .

       

      Please find below the test results for Subscriber for Query test

      ------------------------------------------------------------------------------------

      ------------------------------------------------------------------------------------

      Record Count: 2000000, ThreadCount: 50, Starting Id: 9000000

      (Internal Details) Batch Size: 2000, Task Count: 1000

      Total Number of Records Processed - 2000000

      Time taken for all records to be processed - 399 s

      Average Number of Records Processed Per Second - 5012.0

       

      Similar set up GET operations are as below

       

      Record Count: 2000000, ThreadCount: 50, Starting Id: 9000000

      (Internal Details) Batch Size: 2000, Task Count: 1000

      Total Number of Records Processed - 2000000

      Time taken for all records to be processed - 24 s

      Average Number of Records Processed Per Second - 83333.0

      • 286 Views
      • Tags:
        • 1. Re: ProtobufValueWrapper, Hibernate Search and Slow Query performance
          sannegrinovero
          sannegrinovero May 3, 2015 2:38 PM (in response to prashant.thakur)

          Hi, very interesting tests, thanks for sharing!

           

          First let me clarify how the components fit together. The "Hibernate Search" project is split in multiple components: one which integrates with Hibernate ORM (which obviously is not being used here), one which does Java POJO mapping to Lucene indexable data structures (which is partially used here to map the ProtoBufValueWrapper), and one which implements efficient Lucene index writing and querying. This third component is what Infinispan Query relies on, and the ProtoBufValueWrapper is an adapter to the Integration API to this indexing backend.

          So it's indeed correct and expected to see Hibernate Search components being used, even when using compatibility mode.

           

          What is definitely not expected is to see those threads in the "Hibernate-Search.png" to be busy: those threads should only be active when there are write operations to the index.

          So could you check please:

          • Are you sure only query operations are running, it looks like a lot of write activity is happening
          • Could you check if those threads are really busy? If you're only having Query activity, the sync and commit threads should be just sleeping at best
          • Which versions are you using?

           

          Generally speaking though: yes it is expected that doing a Query is less efficient than doing a Get operation. I wouldn't expect such a significant difference though, so it's worth investigating especially as you shouldn't have those write threads.

            • Actions
          • 2. Re: ProtobufValueWrapper, Hibernate Search and Slow Query performance
            prashant.thakur
            prashant.thakur May 4, 2015 3:18 AM (in response to sannegrinovero)

            Thanks for reply We are presently using 7.0.2.Final . Tried upgrading to 7.1.1.Final but facing some errors related to ProtobufValueWrapeer here hence moved back to 7.0.2.

            These errors are not seen when we use 7.0.2 with same setup other than version number changed to 7.1.1.

            I will check the other parts but if you can help on this we will move to 7.1.1 immediately as Release notes mentions some improvements in the version related to Query.

             

             

            4/May 12:33:16,172  INFO [IndexUpdater] [pool-15-thread-1] (IndexUpdater.java:50) - ISPN014016: Purging instances of 'org.infinispan.query.remote.indexing.ProtobufValueWrapper' from the index

            04/May 12:33:16,173 ERROR [DistributedExecutorMassIndexer] [main] (DistributedExecutorMassIndexer.java:122) - ISPN014018: Error executing MassIndexer

            java.util.concurrent.ExecutionException: java.lang.NullPointerException

              at java.util.concurrent.FutureTask.report(FutureTask.java:122)

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

              at org.infinispan.commons.util.concurrent.NotifyingFutureImpl.get(NotifyingFutureImpl.java:77)

              at org.infinispan.distexec.DefaultExecutorService$LocalDistributedTaskPart.getResult(DefaultExecutorService.java:1109)

              at org.infinispan.distexec.DefaultExecutorService$DistributedTaskPart.innerGet(DefaultExecutorService.java:857)

              at org.infinispan.distexec.DefaultExecutorService$DistributedTaskPart.get(DefaultExecutorService.java:837)

              at org.infinispan.query.impl.massindex.DistributedExecutorMassIndexer$ExecutionResult.waitForAll(DistributedExecutorMassIndexer.java:118)

              at org.infinispan.query.impl.massindex.DistributedExecutorMassIndexer$ExecutionResult.access$000(DistributedExecutorMassIndexer.java:100)

              at org.infinispan.query.impl.massindex.DistributedExecutorMassIndexer.start(DistributedExecutorMassIndexer.java:51)

              at com.subex.spark.common.distributedcaching.server.IspnDistributedCacheServer.start(IspnDistributedCacheServer.java:549)

              at com.subex.spark.DistTestServer.main(DistTestServer.java:50)

            Caused by: java.lang.NullPointerException

              at org.infinispan.query.backend.QueryInterceptor.purgeIndex(QueryInterceptor.java:211)

              at org.infinispan.query.backend.QueryInterceptor.purgeIndex(QueryInterceptor.java:206)

              at org.infinispan.query.impl.massindex.IndexUpdater.purge(IndexUpdater.java:51)

              at org.infinispan.query.impl.massindex.IndexWorker.preIndex(IndexWorker.java:55)

              at org.infinispan.query.impl.massindex.IndexWorker.call(IndexWorker.java:76)

              at org.infinispan.query.impl.massindex.IndexWorker.call(IndexWorker.java:30)

              at org.infinispan.commands.read.DistributedExecuteCommand.perform(DistributedExecuteCommand.java:98)

              at org.infinispan.distexec.DefaultExecutorService$LocalDistributedTaskPart$1.doLocalInvoke(DefaultExecutorService.java:1136)

              at org.infinispan.distexec.DefaultExecutorService$LocalDistributedTaskPart$1.call(DefaultExecutorService.java:1126)

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

              at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)

              at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)

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

              • Actions
            • 3. Re: ProtobufValueWrapper, Hibernate Search and Slow Query performance
              prashant.thakur
              prashant.thakur May 4, 2015 4:43 AM (in response to sannegrinovero)

              One optimization we are doing is exposing our own DataContainer instead of DefaultDataContainer can this be causing IndexWriters to be spawned. We expect Lucent Indexes to be storing ID value only and not the complete key at the leaf node. So whenever a data is expected from Infinispan it would do a get based on key stored at Leaf for complete data.

              Which accoording to our understanding shouldn't have spawned IndexWriter jobs as we are doing only query.

              But is it possible that Index Writer is depending on Actual Value part and recreates it each time with some KeyValueAction whenever required which might result in IndexWrters being spawned.

                • Actions
              • 4. Re: ProtobufValueWrapper, Hibernate Search and Slow Query performance
                prashant.thakur
                prashant.thakur May 5, 2015 1:08 AM (in response to sannegrinovero)

                HI Sanne,

                 

                Moving to latest version of Infinispan helped improve performance 3 fold. Do you have any other tuning suggestion which we can do to improve it 2x further i.e. around 30k which is our target figure ?

                 

                With same dataset the performance has improved by 3x than earlier results with latest version of Infinispan.

                The latest benchmark numbers with 1 Node is ~15k/sec vis-à-vis 5k observed earlier for 50 Client threads.

                 

                ------------------------------------------------------------------------------------

                Record Count: 2000000, ThreadCount: 50, Starting Id: 9000000

                (Internal Details) Batch Size: 2000, Task Count: 1000

                Total Number of Records Processed - 2000000

                Time taken for all records to be processed - 132 s

                Average Number of Records Processed Per Second - 15151.0

                  • Actions
                • 5. Re: ProtobufValueWrapper, Hibernate Search and Slow Query performance
                  prashant.thakur
                  prashant.thakur May 5, 2015 1:10 AM (in response to prashant.thakur)

                  This problem got resolved by passing parameters programatically.

                   

                  SearchMapping mapping = new SearchMapping();
                  mapping.entity(classType).indexed().providedId() ;
                  Properties props = new Properties();
                  props.put(org.hibernate.search.cfg.Environment.MODEL_MAPPING, mapping);
                  configurationBuilder.indexing().withProperties(props);
                    • Actions
                  • 6. Re: ProtobufValueWrapper, Hibernate Search and Slow Query performance
                    sannegrinovero
                    sannegrinovero May 5, 2015 7:34 PM (in response to prashant.thakur)

                    Hi,

                    that's a nice improvement. Which version? Infinispan 7.2.0.Final was released yesterday.

                     

                    To improve your performance significantly, I would hope you could debug your system and verify why you are having writes happening? A single query is various orders of magnitude faster than a write operation, so in that case it would be easy to reach your target figure.

                     

                    Also consider that there's a Flag which you can use: org.infinispan.context.Flag.SKIP_INDEXING

                    This flag should not be necessary for non-write operations, but if something is wrong in the detection of that, you can force it. I wouldn't know how a custom container would affect this though: it would be nice if you could figure out why you're having those writes.

                      • Actions