Uploaded image for project: 'Blazegraph (by SYSTAP)'
  1. Blazegraph (by SYSTAP)
  2. BLZG-652

Add cache for access to historical index views on the Journal by name and commitTime.

    Details

    • Type: New Feature
    • Status: Done
    • Resolution: Done
    • Affects Version/s: BIGDATA_RELEASE_1_2_0
    • Fix Version/s: None
    • Component/s: Journal

      Description

      Access to historical index views is a hot spot during concurrent query. This can be observed in the following table. Except for the read(), everything in that table is being driven by SPORelation.getIndex() and LexiconRelation.getIndex().

      Time (ms)	Name
      75580	com.bigdata.bop.engine.ChunkedRunningQuery$ChunkTask.call()
      42770	com.bigdata.journal.AbstractJournal.getCommitRecord(long)
      42410	com.bigdata.journal.CommitRecordIndex.find(long)
      34620	com.bigdata.btree.Node.indexOf(byte[])
      33840	sun.nio.ch.FileChannelImpl.read(ByteBuffer, long)
      26890	com.bigdata.rdf.spo.SPORelation.getIndex(IKeyOrder)
      ...     ....
      

      The back traces are as follows:

      Time (ms)	Name	Level
      42410	com.bigdata.journal.CommitRecordIndex.find(long)	 "1"
      	com.bigdata.journal.AbstractJournal.getCommitRecord(long)	 "2"
      27500	com.bigdata.journal.Journal.getIndexSources(String, long)	 "3"
      	com.bigdata.journal.Journal.getIndex(String, long)	 "4"
      	com.bigdata.journal.Journal.getIndex(String, long)	 "5"
      	com.bigdata.relation.AbstractRelation.getIndex(IIndexManager, String, long)	 "6"
      	com.bigdata.relation.AbstractRelation.getIndex(String)	 "7"
      	com.bigdata.relation.AbstractRelation.getIndex(IKeyOrder)	 "8"
      20810	com.bigdata.rdf.spo.SPORelation.getIndex(IKeyOrder)	 "9"
      5030	com.bigdata.rdf.lexicon.LexiconRelation.getId2TermIndex()	 "9"
      1660	com.bigdata.rdf.lexicon.LexiconRelation.getBlobsIndex()	 "9"
      14910	com.bigdata.relation.locator.DefaultResourceLocator.locateResourceOn(IIndexManager, String, long)	 "3"
      

      This issue mainly effects the Journal. The IndexManger class on the cluster already has a cache for this.

      ----

      Add a cache by (name,commitTime) to AbstractJournal to remove this hotspot.

        Issue Links

          Activity

          Hide
          bryanthompson bryanthompson added a comment -

          Modified the Tx, AbstractLocalTransactionManager, and
          JournalTransactionService to track read-only transactions as well as
          read-write transactions and re-enabled the indexCache on
          AbstractJournal. This indexCache now passes a unit test in TextTx
          which is focused on the precise semantics of the cache and which
          depends access to the readsOnCommitTime for the transaction. It shows
          that the indexCache is correctly populated by only one entry for a
          named index when two different transactions request views of that
          index. Public methods were added to AbstractJournal to reveal the
          size of the indexCache and historicalIndexCache in order to write this
          test.

          The RWJournal and AST/SPARQL test suites are good. I am committing
          this in order to get feedback from CI and measure the impact of this
          change on concurrent query performance.

          Committed revision r6275.

          Show
          bryanthompson bryanthompson added a comment - Modified the Tx, AbstractLocalTransactionManager, and JournalTransactionService to track read-only transactions as well as read-write transactions and re-enabled the indexCache on AbstractJournal. This indexCache now passes a unit test in TextTx which is focused on the precise semantics of the cache and which depends access to the readsOnCommitTime for the transaction. It shows that the indexCache is correctly populated by only one entry for a named index when two different transactions request views of that index. Public methods were added to AbstractJournal to reveal the size of the indexCache and historicalIndexCache in order to write this test. The RWJournal and AST/SPARQL test suites are good. I am committing this in order to get feedback from CI and measure the impact of this change on concurrent query performance. Committed revision r6275.
          Hide
          bryanthompson bryanthompson added a comment -

          I am still seeing growth in the indexCache. I am disabling it again in order to look into this further.

          Committed revision r6276.

          Show
          bryanthompson bryanthompson added a comment - I am still seeing growth in the indexCache. I am disabling it again in order to look into this further. Committed revision r6276.
          Hide
          bryanthompson bryanthompson added a comment -

          There was a bug in the new unit test in TestTx. Name2Addr was NOT supposed to show up in the indexCache (cache by name+timestamp) even though it shows up in the historicalIndexCache (canonicalizing cache by addr). I have updated the test and documented this wrinkle.

          I had also missed a code path in Journal#getIndex(name,timestamp) where we needed to resolve the Tx object for read-only transactions as well as read-write transactions.

          The indexCache is now enabled again.

          Committed revision r6277.

          Show
          bryanthompson bryanthompson added a comment - There was a bug in the new unit test in TestTx. Name2Addr was NOT supposed to show up in the indexCache (cache by name+timestamp) even though it shows up in the historicalIndexCache (canonicalizing cache by addr). I have updated the test and documented this wrinkle. I had also missed a code path in Journal#getIndex(name,timestamp) where we needed to resolve the Tx object for read-only transactions as well as read-write transactions. The indexCache is now enabled again. Committed revision r6277.
          Hide
          bryanthompson bryanthompson added a comment -

          Running BSBM 100M now. The indexCache is now stable at 7. The historicalIndexCache is stable at 8 (it includes Name2Addr). The active transactions map size is approximately the #of concurrent clients. So, that all looks good.

          Performance seems like it might be slightly higher, there is not as much of a gain as I would have expected based on the profiler data. The results from the start of 120 passes over BSBM 100M with the reduced query mix (without Q5) are inline below. These data are on a mac mini. It seems likely that we will wind up adding 1-2k QMpH with this change. Once I get that data point, I will put a profiler on the system again and see how the bottleneck has been shifted by this change.

          QMpH:                   15049.35 query mixes per hour
          QMpH:                   43864.70 query mixes per hour
          QMpH:                   50753.20 query mixes per hour
          QMpH:                   50901.69 query mixes per hour
          QMpH:                   51316.45 query mixes per hour
          QMpH:                   51999.25 query mixes per hour
          QMpH:                   51926.92 query mixes per hour
          QMpH:                   51398.10 query mixes per hour
          QMpH:                   51817.35 query mixes per hour
          QMpH:                   52989.71 query mixes per hour
          QMpH:                   51201.41 query mixes per hour
          QMpH:                   51740.66 query mixes per hour
          QMpH:                   51776.69 query mixes per hour
          QMpH:                   53631.72 query mixes per hour
          QMpH:                   51496.33 query mixes per hour
          QMpH:                   53390.71 query mixes per hour
          QMpH:                   51258.63 query mixes per hour
          QMpH:                   53540.45 query mixes per hour
          QMpH:                   51107.08 query mixes per hour
          QMpH:                   53549.54 query mixes per hour
          QMpH:                   51673.42 query mixes per hour
          QMpH:                   53382.96 query mixes per hour
          
          Show
          bryanthompson bryanthompson added a comment - Running BSBM 100M now. The indexCache is now stable at 7. The historicalIndexCache is stable at 8 (it includes Name2Addr). The active transactions map size is approximately the #of concurrent clients. So, that all looks good. Performance seems like it might be slightly higher, there is not as much of a gain as I would have expected based on the profiler data. The results from the start of 120 passes over BSBM 100M with the reduced query mix (without Q5) are inline below. These data are on a mac mini. It seems likely that we will wind up adding 1-2k QMpH with this change. Once I get that data point, I will put a profiler on the system again and see how the bottleneck has been shifted by this change. QMpH: 15049.35 query mixes per hour QMpH: 43864.70 query mixes per hour QMpH: 50753.20 query mixes per hour QMpH: 50901.69 query mixes per hour QMpH: 51316.45 query mixes per hour QMpH: 51999.25 query mixes per hour QMpH: 51926.92 query mixes per hour QMpH: 51398.10 query mixes per hour QMpH: 51817.35 query mixes per hour QMpH: 52989.71 query mixes per hour QMpH: 51201.41 query mixes per hour QMpH: 51740.66 query mixes per hour QMpH: 51776.69 query mixes per hour QMpH: 53631.72 query mixes per hour QMpH: 51496.33 query mixes per hour QMpH: 53390.71 query mixes per hour QMpH: 51258.63 query mixes per hour QMpH: 53540.45 query mixes per hour QMpH: 51107.08 query mixes per hour QMpH: 53549.54 query mixes per hour QMpH: 51673.42 query mixes per hour QMpH: 53382.96 query mixes per hour
          Hide
          bryanthompson bryanthompson added a comment -

          So, this raised performance by ~ 1500 QMpH. We still have occasional cache misses on the DefaultResourceLocator, which turn into reads through to getCommitRecordIndex(). I am not sure why...

          It seems likely that the next win might come from a finger [1]. That could reduce key comparison costs (only 1%). It could also eliminate some potential contention during top-down navigation. Node.indexOf(byte[]) shows up as 18%, but most of that is going to be waiting for IO.

          Here are some interesting breakdowns of the total time:


          - 23% Parsing SPARQL queries
          - 17% Executing SPARQL queries (optimization plus evaluation)
          - 14% Query optimization (it looks like we spend MUCH more time optimizing queries than we do evaluating them).

          That suggests that the fat may be the AST itself per an email thread earlier today.

          [1] https://sourceforge.net/apps/trac/bigdata/ticket/543 (Index Finger)

          Show
          bryanthompson bryanthompson added a comment - So, this raised performance by ~ 1500 QMpH. We still have occasional cache misses on the DefaultResourceLocator, which turn into reads through to getCommitRecordIndex(). I am not sure why... It seems likely that the next win might come from a finger [1] . That could reduce key comparison costs (only 1%). It could also eliminate some potential contention during top-down navigation. Node.indexOf(byte[]) shows up as 18%, but most of that is going to be waiting for IO. Here are some interesting breakdowns of the total time: - 23% Parsing SPARQL queries - 17% Executing SPARQL queries (optimization plus evaluation) - 14% Query optimization (it looks like we spend MUCH more time optimizing queries than we do evaluating them). That suggests that the fat may be the AST itself per an email thread earlier today. [1] https://sourceforge.net/apps/trac/bigdata/ticket/543 (Index Finger)

            People

            • Assignee:
              bryanthompson bryanthompson
              Reporter:
              bryanthompson bryanthompson
            • Votes:
              0 Vote for this issue
              Watchers:
              2 Start watching this issue

              Dates

              • Created:
                Updated:
                Resolved: