Record manager peformance

Kevin Day
2005-07-29
2013-06-03
  • Kevin Day
    Kevin Day
    2005-07-29

    In my early tests with jdbm, I found that it was significantly faster to store values in a BTree than to use the RecordManager directly.

    Originally, I thought the performance was related to the fact that the file was being read one record at a time - but I just looked at the code, and I'm not so sure that's the issue.  It appears that the RecordFile object reads data in 8192 byte blocks - this should map quite nicely to the file system's block size...

    So why in the heck is it so much more efficient to store values in the BTree (indexed by a recid) vs just storing them as raw records in the record manager?

    It can't be the order in which objects are being added - my tests were all adding objects with sequential recids/key values.

    It can't be that the BTreePage could be bigger than the 8192 byte block - the RecordFile saves things in 8192 byte chunks no matter how much space the object being stored consumes.

    I'd love to hear any theories...  I'm going to put together a quick test harness to make sure I'm not completely off base here.

    - K

     
    • Alex Boisvert
      Alex Boisvert
      2005-07-29

      I'd like to see numbers before we jump to conclusions but that being said there's a fundamental difference between the way BTrees and normal records are stored.

      With a BTree and large page size (say, 16+) we load one record from the RecordManager by seeking and reading from the disk (two native/kernel calls).  We deserialize the objects and obtain about 16 values in one swoop.

      If you're going for through the RecordManager to retrieve 16 individual objects, you're going to seek and read for each individual record you retrieve.

      There is no caching/optimization at the RecordFile level; caching only happens at the deserialized record level.

      This may help explain the gap you are seeing.

      alex

       
      • Kevin Day
        Kevin Day
        2005-07-29

        alex-

        Unless my test has a memory leak somewhere, then the results show that adding to the BTree is about 2-3 times faster for batch *inserts*.

        Note:  Your comment on retrieval speeds is well taken, and I completely agree.  However, I'm still not understanding why the insert speeds would be so different.  For the time being, I am focusing on  inserts alone (retrieval will certainly be optimized using the trees - as long as the records can be intelligently clustered).

        Just to make sure I understand what's going on with the record manager - please correct me if any of the following is incorrect: 

        a)  Every time I insert a new item to the record manager directly, it is being written, immediately, to disk (I have transactions turned off).

        b)  If I insert the item into a BTree, new objects are only inserted into the record manager if a new BPage is required for the insert. 

        The piece of this that is still confusing to me is that it is pretty clear that the BTree and BPage objects both call update() on the record manager whenever they change (i.e. as soon as a value is inserted).  Unless there is a huge performance hit for doing an insert (vs an update) in the record manager, I would think that there wouldn't be much difference from this vs. individual inserts at the record manager level.

        Indeed, I would expect the BTree performance to be slightly worse, because the amount of data stored by a BPage is going to be more than for just an individual value object (of course, file system paging could take away this advantage)...

        I'm looking forward to hearing your thoughts on this!

        - K

         
        • Alex Boisvert
          Alex Boisvert
          2005-07-29

          Hmmm.  I think the test doesn't compare apples to apples. 

          I think there's a discrepancy between the I/O load between the RecordManager test and the BTree test.  The test assumes that each Object inserted in the BTree takes 158 bytes.  That's not true.  The BPage uses a single ObjectOutputStream for all key/values stored on the page and therefore Objects take less space (I'm guessing somewhere around 142 bytes fixed + 16 bytes per object).

          You could confirm this by comparing the file sizes between a record file using only BTrees and a record file using only the RecordManager-inserted objects.

          You might want to use the same Serializer for both tests.

          alex

           
      • Bryan Thompson
        Bryan Thompson
        2005-07-29

        I think that I understand why Kevin is seeing the improvement using the btree to store values in his application - it is behaving like a clustered index and increases the likelyhood that the btree pages required to materialize the next application object are already in cache.

        I think that optimal processing for this kind of approach will require modifying the tuple browser to support traversal under concurrent modification and processing the application records in sequence from the btree.  This is what relational databases are doing when they have a clustered index giving a natural row ordering.

        I think that the insert penalty (if any) for the recman is that each insert is really a write through to disk and allocates a new object in the store.  In contrast, insert of objects into the btree only insert a new BTree page into the store more or less once the last one has been filled (if you are doing key order inserts).

        An update to an object in the cache is MUCH faster.

        If you have turned off the cache (and I think that "jdbm.disableTransactions" is disabling the in-memory transaction buffer, not the cache, right?), then each update requires a write to the disk.  But if you are inserting objects into the btree, that is still reusing the same BPage until it gets full and then it allocates a new one.

        The record manager is responsible for all those BPage allocations and retrievals.  The Btree simply can not be "out-performing" the record manager on an apples to apples basis since it exists over the recman.

        How about a test that reads a random record from a btree and from the recman?  Generate 100k or 1M records and then fetch them randomly and look at the per-fetch time.  Recman has got to be faster at retrieving an object from the store by recid compare to the btree retrieving an object by a key since the latter involves mutiple recman fetches while the former only takes one.

        -bryan

         
        • Kevin Day
          Kevin Day
          2005-07-29

          Bryan-

          I'm not sure I agree with this explanation.  Caching is used for reading/lookup only - not inserts.  By my reading of the source, with transactions disabled, Inserts and Updates are written immediately to disk...

          hmmmm - actually, on reading a bit further, it looks like dirty file pages are help on to by the record manager until a commit() is called...  that's interesting.  does this mean that commit() is required, even if transactions are turned off?  That could explain my heap space error...

          Can someone please confirm that a call to commit() is required, even if transactions are turned off?

          I still don't think that this really makes a difference to the apples/apples test results, though.  All it means is that the test results I have so far are even more useful, because they cache all writes to disk until the very end of the run, when close() is called on the record manager.

          If that's the case, then it would indicate one of two things:

          a)  There is a fundamental performance issue with writing lots of smallish objects to the record manager

          or

          b)  There is a lot more data being written to disk when writing lots of smallish objects to the record manager.

          I'm going to check the file sizes for each test and see if I can tell what's going on.

          Cheers!

          - K

           
          • Kevin Day
            Kevin Day
            2005-07-29

            OK - test results for database file sizes:

            Added 10000 records
            rmDirect: 1625 mills - 6153 recs/sec
            btree: 1250 mills - 8000 recs/sec
            rmDirect db filesize = 1712128
            btree db filesize = 1892352

            The files are pretty close to each other in size.  As would be expected, the BTree implementation takes a bit more disk space because of the overhead of the extra BPage objects.

            I'll check performance before calling close() next (I'm almost positive that the PhyiscalRowIDManager is caching dirty pages).

            - K

             
            • Kevin Day
              Kevin Day
              2005-07-29

              Added 10,000 records
              rmDirect: 1562 mills - 6402 recs/sec
              rmDirect before close(): 1218 mills - 8210 recs/sec
              btree: 1172 mills - 8532 recs/sec
              btree before close: 406 mills - 24630 recs/sec
              rmDirect db filesize = 1712128
              rmDirect db filesize before close() = 0
              btree db filesize = 1892352
              btree db filesize before close() = 0

              Added 100,000 records
              rmDirect: 11234 mills - 8901 recs/sec
              rmDirect before close(): 9609 mills - 10406 recs/sec
              btree: 4813 mills - 20777 recs/sec
              btree before close: 2922 mills - 34223 recs/sec
              rmDirect db filesize = 16867328
              rmDirect db filesize before close() = 0
              btree db filesize = 17506304
              btree db filesize before close() = 0

              It is pretty clear that nothing is being written to disk before close() is called.

              It is also clear that there is a substantial hit on adding to the record manager directly...

              I wonder.... maybe the performance hit is because the dirty page hash table in the record manage is having to expand itself, copy it's contents, etc...

              I'm going to adjust things so I commit every 500 records and see what happens then.

              - K

               
              • Kevin Day
                Kevin Day
                2005-07-29

                Added 1000000 records, commit every 500 records
                rmDirect: 94219 mills - 10613 recs/sec
                rmDirect before close(): 92657 mills - 10792 recs/sec
                btree: 42047 mills - 23782 recs/sec
                btree before close: 39906 mills - 25058 recs/sec
                rmDirect db filesize = 168460288
                rmDirect db filesize before close() = 360448
                btree db filesize = 172572672
                btree db filesize before close() = 170508288

                Doing the commit() periodically definitely got rid of the heap space issue.  I'm pretty sure that the dirty hashmap was growing unctrollably.

                Anyway, I've now taken the growth of the dirty pool under control.  Results still show a significant performance advantage to BTree insertions vs direct record manager insertions (about 2:1 improvement).

                The before and after close() numbers now line up (this is to be expected, now that we are hitting commit() on a periodic basis).

                I do find it quite interesting that the file size of the recordmanager test is quite small before close() gets called.  Especially in light of the fact that the BTree test's file size is similar to it's final file size.

                Does this imply that there is some other type of record caching going on in the record manager (outside of the dirty page hashmap) that is impacting what actually gets written to disk?

                I guess the implication of all of this is that if I write 1000 records that are 100 bytes in length to the record manager that the performance is going be drastically different than if I write 100 records that are 1000 bytes in length.

                Given that the page manager is caching dirty records and only writing them to disk when we call commit(), I'm struggling to see why there would be a substantial difference...  Unless there is something about the insert() call to the record manager that is very time consuming.

                I think I've begun to demonstrate that this insert() performance hit is not related to writing to the disk.  We see the same results even if data never gets written to disk.

                So - what's insert() doing that is taking so much time?  Or am I completely off my rocker?

                It might be time for me to get that profiler installed for Eclipse and see if I can see where the time is getting consumed....

                Does anyone have any thoughts or suggestions on where to start looking?

                - K

                 
                • Bryan Thompson
                  Bryan Thompson
                  2005-07-29

                  Kevin,

                  I am very keen on tracking down this heap issue.  I have an application where (for integration purposes) it is not practical to commit the entire transaction until it is finished, so it is important the jdbm do the right thing and start writing dirty records to disk and releasing them from memory.  Can you suggest some unit tests that might help to identify the problem?

                  -bryan

                   
                  • Kevin Day
                    Kevin Day
                    2005-08-01

                    Bryan-

                    I think I may even know where the problem is, and I have a decent idea on how to fix it...

                    In the RecordFile class, a set of dirty pages are stored in a HashMap.  This map is allowed to grow indefinitely, until a commit() is called.  This is the desired behavior is transactions are enabled, but if transactions are not enabled, then it will just grow.

                    I think this is the source of the heap overflow (although I haven't put a profiler on this to check it out).  There may be other page caches like this elsewhere in jdbm that only get flushed when commit() is called...

                    I *think* that the proper behavior here is to have a maximum dirty page pool size that takes effect if transactions are disabled.  When the pool grows to that size, they are automatically written to disk with an internal call to RecordFile.commit().

                    I think the place to do the dirty pool size check is going to be inside RecordFile.release(BlockIo).  That appears to be the only place that items are actually added to the dirty pool.

                    My only concern with doing the check there is that commit() can throw an IOException and release() does not throw an IOException.

                    We will either need to change the method signature to add the exception, or we'll need to swallow the exception...

                    Anyone have any thoughts?

                    Cheers,

                    - K

                     
                    • Bryan Thompson
                      Bryan Thompson
                      2005-08-02

                      Kevin,

                      I would like to get a clarification of the intended semantics of jdbm when the "jdbm.disableTransactions" flag is true and when it is false.  My understanding was that transactions are always enabled, but what the flag determines is whether an in-memory transaction buffer is maintained or whether the transaction is solely buffered on disk.  I remember reading this somewhere -- perhaps in another thread of the open discussion?

                      If my reading of this flag is correct, then perhaps the in-memory size of the transaction buffer should probably be limited in both cases (when the flag is true and when it is false) since otherwise a large transaction can run out of memory.  However, I have not looked at all into how transactions are actually processed.

                      The change that you are suggesting seems like it would have the consequence that you can not rollback past the last implicit commit of dirty pages.

                      -bryan

                       
                      • Kevin Day
                        Kevin Day
                        2005-08-02

                        I can't speak to what the *intent* is - but I can look at the code and tell what's going on.

                        If transactions are disabled, a commit() on the RecordFile results in all dirty blocks being written to disk.  If transactions are enabled, then a RecordFile commit() causes the blocks to be moved from the dirty list into the transaction manager, then commit() is called on the transaction manager (where they are then written to the log file).

                        So, the basic description you give is technically correct, although the wording is a bit inconsistent with the JDBM implementation.

                        The RecordFile class maintains a list of dirty pages, and it is possible to roll back those dirty pages.  I'm not sure if this is really technically a transaction...  It allows rollback, but there is no guarantee of atomicity.  The TransactionManager provides for atomicity.

                        If transactions are enabled, then I do not believe that it is safe to flush the dirty buffer to disk periodically (doing so would invalidate the active transaction).  That flush needs to occur in the context of the active transaction.  Making this possible would require that the data required to undo the writes also be added to the log - something that the current implementation does not appear to be designed to do.

                        Personally, I'm willing to do huge changes outside of a transaction.  I actually do a meta quasi-transaction on the entire database file when I do mass updates like this - i.e. I copy the file to a temp location, create a marker file that the file is in a transaction, make the changes to the db file, then delete the marker and the temp file.  If the marker is present during startup, then the db file is deleted, and replaced with the temp file.  This, of course, only works if you have the luxury of taking the database off-line for big transactions...

                        Finally, the change I'm suggesting would absolutely have the consequence you describe.  Given that, maybe it would make sense to disallow the rollback() method if transactions are disabled?

                        - K

                         
          • Bryan Thompson
            Bryan Thompson
            2005-07-29

            Kevin,

            I am thinking that writing a lot of small objects using the record manager is less efficient than writing them using the btree since the btree aggregates the updates on each page.

            I have been working on an unordered variant of the "container" facility provided by the btree page.  I have been doing this at the level of our framework, but I could see migrating it down to the jdbm level.

            Basically, it makes it possible for an object to logically be a container of other objects without having any ordering semantics within the container.  Logical containers are broken down into a linked list of "physical containers", each of which is more or less equivilent to the BPage - it holds a set of values, but no keys (since the data are not inherently ordered).

            When an application object is inserted into a logical container there is some logic for figuring out which physical container the object is actually placed within.  Basically, I check the primary container and if it is full, I insert into the tail and rotate any full containers to the head of the list and any containers where there is empty space to the tail of the list.

            There is a trick of course.  I have to munge the jdbm recids in order to distinguish the address of a physical container from the address of an object within that container, but this is actually proving quite straight forward.

            So, to echo your statements in another thread, the recman is not doing anything wrong, but it is not aggregating inserts either, so the btree wins on insert since there are net fewer inserts actually be performed at the recman level.  Most of the application object inserts are actually updates of some pre-existing BPage.

            -bryan

             
    • Kevin Day
      Kevin Day
      2005-07-29

      OK - I've got what should be a super simple test (please let me know if anything here is dubious for doing an apples-to-apples comparison of BTree insertions vs Recmanager insertions).

      Database files are deleted and re-created for each test.

      Transactions are disabled.

      All tests run on a local IDE drive, Java in regular runtime mode (not debug), AMD 750 MHz, 768 MB RAM.

      I am seeing one thing that makes question the tests a little bit:  If I up the test so it adds 1,000,000 records, I'm getting an out of heap space error in the JVM.  I've got transactions turned off, and I'm not holding on to any object references (the code is too simple for that)...  Can anyone suggest what I might be doing wrong (see code below)?:

      Results:

      Added 1000 records
      rmDirect: 593 mills - 1686 recs/sec
      btree: 516 mills - 1937 recs/sec

      Added 10000 records
      rmDirect: 2531 mills - 3951 recs/sec
      btree: 1391 mills - 7189 recs/sec

      Added 100000 records
      rmDirect: 19547 mills - 5115 recs/sec
      btree: 6515 mills - 15349 recs/sec

      Here's the code for the test:

      /*
      * Created on Jul 29, 2005
      * (c) 2005 Trumpet, Inc.
      *
      */
      package com.trumpetinc.testjdbm.test;

      import java.io.File;
      import java.io.IOException;
      import java.util.Properties;

      import jdbm.RecordManager;
      import jdbm.RecordManagerFactory;
      import jdbm.btree.BTree;
      import jdbm.helper.LongComparator;
      import jdbm.helper.LongSerializer;
      import jdbm.helper.Serializer;

      /**
      * @author kevin
      */
      public class PerformanceCompare {

          LongComparator longComparator = new LongComparator();
          LongSerializer longSerializer = new LongSerializer();

         
          static private class SimpleSerializer implements Serializer{
              public static SimpleSerializer INSTANCE = new SimpleSerializer();
             
              public byte[] serialize(Object obj) throws IOException {
                  // we are just returning something to consume space
                  return new byte[150];
              }

              public Object deserialize(byte[] serialized) throws IOException {
                  // There was nothing in the data anyway, so just create a new object and return it
                  return new Object();
              }
             
          }
         
          public String getTestDBFileRoot(){
              return new File(this.getClass().getName() + "_test").getAbsolutePath();
          }
         
          public boolean deleteTestDBFile(){
              File dbFile = new File(getTestDBFileRoot() + ".db");
              File logFile = new File(getTestDBFileRoot() + ".lg");
              if (dbFile.exists() && !dbFile.delete()) return false;
              return logFile.exists() ? logFile.delete() : true;
             
          }
         
          public RecordManager getTestRecordManager() throws IOException{
              RecordManager recman = null;
             
              // next, create or open BR record manager
              Properties props = new Properties();
              props.setProperty("jdbm.disableTransactions", "true");
              recman = RecordManagerFactory.createRecordManager( getTestDBFileRoot() , props );
             
              return recman;
          }
         
          public RecordManager getCleanTestRecordManager() throws IOException{
              if (!deleteTestDBFile()) return null;
             
              return getTestRecordManager();
          }
         
          public void testRMDirect(RecordManager rm, int recordsToAdd) throws IOException{
              Object obj = new Object();
              for(int i = 1; i <= recordsToAdd; i++){
                  long recid = rm.insert(obj, SimpleSerializer.INSTANCE);
              }
          }

          public void testBTree(RecordManager rm, int recordsToAdd) throws IOException{
              Object obj = new Object();
              BTree bt = BTree.createInstance(rm, longComparator, longSerializer, SimpleSerializer.INSTANCE, 26); // 26 ~= 4096 (FSblock size) / 158 (object size + key size)
              for(int i = 1; i <= recordsToAdd; i++){
                  bt.insert(new Long(i), obj, false);
              }
          }
         
         
          /**
           * @param args
           * @throws IOException
           */
          public static void main(String[] args) throws IOException {
              PerformanceCompare c =new PerformanceCompare();
             
              int recsToAdd = 1000000;
             
              RecordManager rm = null;
             
              rm = c.getCleanTestRecordManager();
              long startTime = System.currentTimeMillis();
              c.testRMDirect(rm, recsToAdd);
              rm.close();
              long rmDirectElapsed = System.currentTimeMillis() - startTime;

             
              rm = c.getCleanTestRecordManager();
              startTime = System.currentTimeMillis();
              c.testBTree(rm, recsToAdd);
              rm.close();
              long btreeElapsed = System.currentTimeMillis() - startTime;
              c.deleteTestDBFile();
             
              System.out.println("Added " + recsToAdd + " records");
              System.out.println("rmDirect: " + rmDirectElapsed + " mills - " + (recsToAdd*1000/rmDirectElapsed) + " recs/sec");
              System.out.println("btree: " + btreeElapsed + " mills - " + (recsToAdd*1000/btreeElapsed) + " recs/sec");
          }

      }

       
      • Bryan Thompson
        Bryan Thompson
        2005-07-29

        Kevin,

        Here are the results on my machine:

        Added 1000000 records
        rmDirect: 75438 mills - 13255 recs/sec
        btree: 49531 mills - 20189 recs/sec

        I mentioned a problem with heap exhaustion in another thread, but it turned out that I was maintaining an object graph.  I *think* that I have resolved that problem, but the heap exhaustion problem remains.  However there is a lot of new code so I don't trust my results yet.

        Heap exhaustion with a simple test case indicates to me that there may be a problem somewhere.  This is something that I definately want to look into further.

        I would appreciate clarification on "jdbm.disableTransactions".  What exactly is it doing?

        -bryan

         
        • Kevin Day
          Kevin Day
          2005-07-29

          Bryan-

          These results are quite close to what I'm seeing.

          I think that if you try calling commit() every 500 inserts, that you'll find your heap space problem goes away (see my other, lengthy post above).

          In case anyone wants it, here is the latest version of my test code (checks for file sizes and times before and after close(), plus calls commit() at specified insertion interval):

          /*
          * Created on Jul 29, 2005
          * (c) 2005 Trumpet, Inc.
          *
          */
          package com.trumpetinc.testjdbm;

          import java.io.File;
          import java.io.IOException;
          import java.util.Properties;

          import jdbm.RecordManager;
          import jdbm.RecordManagerFactory;
          import jdbm.btree.BTree;
          import jdbm.helper.LongComparator;
          import jdbm.helper.LongSerializer;
          import jdbm.helper.Serializer;

          /**
          * @author kevin
          */
          public class PerformanceCompare {
             
              LongComparator longComparator = new LongComparator();
              LongSerializer longSerializer = new LongSerializer();
             
             
              static private class SimpleSerializer implements Serializer{
                  public static SimpleSerializer INSTANCE = new SimpleSerializer();
                 
                  public byte[] serialize(Object obj) throws IOException {
          //            we are just returning something to consume space
                      return new byte[150];
                  }
                 
                  public Object deserialize(byte[] serialized) throws IOException {
          //            There was nothing in the data anyway, so just create a new object and return it
                      return new Object();
                  }
                 
              }
             
              public String getTestDBFileRoot(){
                  return new File(this.getClass().getName() + "_test").getAbsolutePath();
              }
             
              public boolean deleteTestDBFile(){
                  File dbFile = new File(getTestDBFileRoot() + ".db");
                  File logFile = new File(getTestDBFileRoot() + ".lg");
                  if (dbFile.exists() && !dbFile.delete()) return false;
                  return logFile.exists() ? logFile.delete() : true;
                 
              }
             
              public RecordManager getTestRecordManager() throws IOException{
                  RecordManager recman = null;
                 
          //        next, create or open BR record manager
                  Properties props = new Properties();
                  props.setProperty("jdbm.disableTransactions", "true");
                  recman = RecordManagerFactory.createRecordManager( getTestDBFileRoot() , props );
                 
                  return recman;
              }
             
              public RecordManager getCleanTestRecordManager() throws IOException{
                  if (!deleteTestDBFile()) return null;
                 
                  return getTestRecordManager();
              }
             
              public void testRMDirect(RecordManager rm, int recordsToAdd, int commitEvery) throws IOException{
                  Object obj = new Object();
                  for(int i = 1; i <= recordsToAdd; i++){
                      long recid = rm.insert(obj, SimpleSerializer.INSTANCE);
                      if (i % commitEvery == 0){
                          rm.commit();
                      }
                  }
              }
             
              public void testBTree(RecordManager rm, int recordsToAdd, int commitEvery) throws IOException{
                  Object obj = new Object();
                  BTree bt = BTree.createInstance(rm, longComparator, longSerializer, SimpleSerializer.INSTANCE, 26); // 26 ~= 4096 (FSblock size) / 158 (object size + key size)
                  for(int i = 1; i <= recordsToAdd; i++){
                      bt.insert(new Long(i), obj, false);
                      if (i % commitEvery == 0){
                          rm.commit();
                      }
                  }
              }
             
             
              /**
               * @param args
               * @throws IOException 
               */
              public static void main(String[] args) throws IOException {
                  PerformanceCompare c =new PerformanceCompare();
                 
                  int recsToAdd = 1000000;
                  int commitEvery = 500;
                 
                  RecordManager rm = null;
                 
                  rm = c.getCleanTestRecordManager();
                  File directDBFile = new File(c.getTestDBFileRoot() + ".db");
                  long startTime = System.currentTimeMillis();
                  c.testRMDirect(rm, recsToAdd, commitEvery);
                  long rmDirectElapsedBeforeClose = System.currentTimeMillis() - startTime;
                  long rmDirectDBSizeBeforeClose = directDBFile.length();
                  rm.close();
                  long rmDirectElapsed = System.currentTimeMillis() - startTime;
                     
                  long rmDirectDBSize = directDBFile.length();
                 
                 
                  rm = c.getCleanTestRecordManager();
                  File btreeDBFile = new File(c.getTestDBFileRoot() + ".db");
                  startTime = System.currentTimeMillis();
                  c.testBTree(rm, recsToAdd, commitEvery);
                  long btreeElapsedBeforeClose = System.currentTimeMillis() - startTime;
                  long btreeDBSizeBeforeClose = btreeDBFile.length();
                  rm.close();
                  long btreeElapsed = System.currentTimeMillis() - startTime;
                     
                  long btreeDBSize = btreeDBFile.length();
                  c.deleteTestDBFile();
                 
                  System.out.println("Added " + recsToAdd + " records, commit every " + commitEvery + " records");
                  System.out.println("rmDirect: " + rmDirectElapsed + " mills - " + (recsToAdd*1000/rmDirectElapsed) + " recs/sec");
                  System.out.println("rmDirect before close(): " + rmDirectElapsedBeforeClose + " mills - " + (recsToAdd*1000/rmDirectElapsedBeforeClose) + " recs/sec");
                  System.out.println("btree: " + btreeElapsed + " mills - " + (recsToAdd*1000/btreeElapsed) + " recs/sec");
                  System.out.println("btree before close: " + btreeElapsedBeforeClose + " mills - " + (recsToAdd*1000/btreeElapsedBeforeClose) + " recs/sec");
                  System.out.println("rmDirect db filesize = " + rmDirectDBSize );
                  System.out.println("rmDirect db filesize before close() = " + rmDirectDBSizeBeforeClose );
                  System.out.println("btree db filesize = " + btreeDBSize );
                  System.out.println("btree db filesize before close() = " + btreeDBSizeBeforeClose );
              }
             
          }

           
    • Kevin Day
      Kevin Day
      2005-07-29

      I'm pretty sure I am using the same serializer for both tests, unless I misunderstand which serializer your are referring to.  The record manager uses SimpleSerializer.INSTANCE for it's inserts, and the BTree is configured with SimpleSerializer.INSTANCE as it's value serializer...

      I'm not using standard serialization at all, so ObjectOutputStream should not come into play in this test at all.  Do you see something in my test that indicates that OOS is being used?

      By my thinking, the only items in this test that should be serialized using native serialization (with the huge byte[] overhead associated with that), are the LongSerializer and the SimpleSerializer - and they only get serialized and stored a single time in the BTree (and not at all in the record manager), so I wouldn't think that would matter.

      SimpleSerializer and LongSerializer themselves don't make use of ObjectOutputStream...

      Unless the record manager is serializing the value serializer for each insert???  If it was doing that, then it would have a huge impact on the efficiency.

      OK - I just checked the source - the serializer itself is not serialized, so that's not what is going on.

      So, in my test above, there should be no ObjectOutputStream usage at all.

      Given that, does my test look more like apples-to-apples ?

      thanks!

      - K

       
      • Alex Boisvert
        Alex Boisvert
        2005-07-29

        Yes, agreed;  I didn't realize the BTree was using the same serializer.  Forget about what I said.

        alex

         
    • Kevin Day
      Kevin Day
      2005-07-29

      OK - I have a theory.  I'm not sure how valid this is, but I'll toss it out there.

      What if the call to insert() is much slower for multiple sequential calls than for a single call with larger data size because the PhysicalRowIDManager is having to search for and allocate a new chunk of space for each insert() call?

      If the PhysicalRowIDManager wasn't smart enough to realize that it has already gone through and attempted to find a chunk of free space available in the file, then it could be inneficient in locating the physical location to insert the new page.

      I'm specifically looking at the code in PhysicalRowIDManager.allocNew( int size, long start )

      Anyone have any comments?

      - K

       
      • Bryan Thompson
        Bryan Thompson
        2005-07-29

        Kevin,

        I modified your test to insert larger objects.  As the insert size goes up, recman begins to be the faster solution.  You can see this in these two data points @ 150 bytes and 8k inserts.  I didn't run this out at 100000 objects, but I expect the story will remain the same.

        My theory is that creating new recman objects is more expensive than updating existing pages of a btree.

        The modified test is below:

        -bryan

        ----

        Added 10000 150 byte records, commit every 500 records
        rmDirect: 1062 mills - 9416 recs/sec
        rmDirect before close(): 734 mills - 13623 recs/sec
        btree: 703 mills - 14224 recs/sec
        btree before close: 468 mills - 21367 recs/sec
        rmDirect db filesize = 1712128
        rmDirect db filesize before close() = 1622016
        btree db filesize = 1777664
        btree db filesize before close() = 0

        ----

        Added 10000 8192 byte records, commit every 500 records
        rmDirect: 7047 mills - 1419 recs/sec
        rmDirect before close(): 5984 mills - 1671 recs/sec
        btree: 7297 mills - 1370 recs/sec
        btree before close: 5891 mills - 1697 recs/sec
        rmDirect db filesize = 82329600
        rmDirect db filesize before close() = 78209024
        btree db filesize = 83017728
        btree db filesize before close() = 70483968

        ----

        /*
        * Created on Jul 29, 2005
        * (c) 2005 Trumpet, Inc.
        *
        */
        package com.trumpetinc.testjdbm;

        import java.io.File;
        import java.io.IOException;
        import java.util.Properties;

        import jdbm.RecordManager;
        import jdbm.RecordManagerFactory;
        import jdbm.btree.BTree;
        import jdbm.helper.LongComparator;
        import jdbm.helper.LongSerializer;
        import jdbm.helper.Serializer;

        /**
        * @author kevin
        */
        public class PerformanceCompare {
           
                final Serializer m_serializer;
           
                public PerformanceCompare( int objSize )
                {
                   
                    m_serializer = new SimpleSerializer( objSize );
               
                }
                LongComparator longComparator = new LongComparator();
                LongSerializer longSerializer = new LongSerializer();
               
               
                static private class SimpleSerializer implements Serializer{
                        //public static SimpleSerializer INSTANCE = new SimpleSerializer();
                   
                        final int m_objSize;
                       
                        public SimpleSerializer(int objSize)
                        {
                           
                            m_objSize = objSize;
                           
                        }
                       
                        public byte[] serialize(Object obj) throws IOException {
        //                      we are just returning something to consume space
                                return new byte[m_objSize];
                        }
                       
                        public Object deserialize(byte[] serialized) throws IOException {
        //                      There was nothing in the data anyway, so just create a new object and return it
                                return new Object();
                        }
                       
                }
               
                public String getTestDBFileRoot(){
                        return new File(this.getClass().getName() + "_test").getAbsolutePath();
                }
               
                public boolean deleteTestDBFile(){
                        File dbFile = new File(getTestDBFileRoot() + ".db");
                        File logFile = new File(getTestDBFileRoot() + ".lg");
                        if (dbFile.exists() && !dbFile.delete()) return false;
                        return logFile.exists() ? logFile.delete() : true;
                       
                }
               
                public RecordManager getTestRecordManager() throws IOException{
                        RecordManager recman = null;
                       
        //              next, create or open BR record manager
                        Properties props = new Properties();
                        props.setProperty("jdbm.disableTransactions", "true");
                        recman = RecordManagerFactory.createRecordManager( getTestDBFileRoot() , props
        );
                       
                        return recman;
                }
               
                public RecordManager getCleanTestRecordManager() throws IOException{
                        if (!deleteTestDBFile()) return null;
                       
                        return getTestRecordManager();
                }
               
                public void testRMDirect(RecordManager rm, int recordsToAdd, int commitEvery)
        throws IOException{
                        Object obj = new Object();
                        for(int i = 1; i <= recordsToAdd; i++){
                                long recid = rm.insert(obj, m_serializer );
                                if (i % commitEvery == 0){
                                        rm.commit();
                                }
                        }
                }
               
                public void testBTree(RecordManager rm, int recordsToAdd, int commitEvery)
        throws IOException{
                        Object obj = new Object();
                        BTree bt = BTree.createInstance(rm, longComparator, longSerializer,
        m_serializer, 26); // 26 ~= 4096 (FSblock size) / 158 (object size + key size)
                        for(int i = 1; i <= recordsToAdd; i++){
                                bt.insert(new Long(i), obj, false);
                                if (i % commitEvery == 0){
                                        rm.commit();
                                }
                        }
                }
               
               
                /**
                 * @param args
                 * @throws IOException 
                 */
                public static void main(String[] args) throws IOException {
                   
                        int recsToAdd = 10000;
                        int commitEvery = 500;
                        int objSize = 150;

                        PerformanceCompare c = new PerformanceCompare( objSize );
                       
                        RecordManager rm = null;
                       
                        rm = c.getCleanTestRecordManager();
                        File directDBFile = new File(c.getTestDBFileRoot() + ".db");
                        long startTime = System.currentTimeMillis();
                        c.testRMDirect(rm, recsToAdd, commitEvery);
                        long rmDirectElapsedBeforeClose = System.currentTimeMillis() - startTime;
                        long rmDirectDBSizeBeforeClose = directDBFile.length();
                        rm.close();
                        long rmDirectElapsed = System.currentTimeMillis() - startTime;
                               
                        long rmDirectDBSize = directDBFile.length();
                       
                       
                        rm = c.getCleanTestRecordManager();
                        File btreeDBFile = new File(c.getTestDBFileRoot() + ".db");
                        startTime = System.currentTimeMillis();
                        c.testBTree(rm, recsToAdd, commitEvery);
                        long btreeElapsedBeforeClose = System.currentTimeMillis() - startTime;
                        long btreeDBSizeBeforeClose = btreeDBFile.length();
                        rm.close();
                        long btreeElapsed = System.currentTimeMillis() - startTime;
                               
                        long btreeDBSize = btreeDBFile.length();
                        c.deleteTestDBFile();
                       
                        System.out.println("Added " + recsToAdd + " "+objSize+" byte records, commit every " + commitEvery
        + " records");
                        System.out.println("rmDirect: " + rmDirectElapsed + " mills - "
        + (recsToAdd*1000/rmDirectElapsed) + " recs/sec");
                        System.out.println("rmDirect before close(): " + rmDirectElapsedBeforeClose
        + " mills - " + (recsToAdd*1000/rmDirectElapsedBeforeClose) + " recs/sec");
                        System.out.println("btree: " + btreeElapsed + " mills - " +
        (recsToAdd*1000/btreeElapsed) + " recs/sec");
                        System.out.println("btree before close: " + btreeElapsedBeforeClose + " mills - " + (recsToAdd*1000/btreeElapsedBeforeClose) + " recs/sec");
                        System.out.println("rmDirect db filesize = " + rmDirectDBSize );
                        System.out.println("rmDirect db filesize before close() = "
        + rmDirectDBSizeBeforeClose );
                        System.out.println("btree db filesize = " + btreeDBSize );
                        System.out.println("btree db filesize before close() = " + btreeDBSizeBeforeClose
        );
                }
               
        }

         
        • Bryan Thompson
          Bryan Thompson
          2005-07-30

          Here are results out to 1M records.  At 150 bytes per object, the BTree is twice as fast.  At 8196 bytes per object, the recman is (slightly) faster.  I have to admit that I find this result surprising.  We should also look at access times of course since resolving a recid using recman SHOULD be faster than resolving a key using a BTree.

          -bryan

          Added 1000000 150 byte records, commit every 500 records
          rmDirect: 37110 mills - 26946 recs/sec
          rmDirect before close(): 36516 mills - 27385 recs/sec
          btree: 16922 mills - 59094 recs/sec
          btree before close: 15953 mills - 62684 recs/sec
          rmDirect db filesize = 168460288
          rmDirect db filesize before close() = 532480
          btree db filesize = 172572672
          btree db filesize before close() = 159825920

          Added 1000000 8192 byte records, commit every 500 records
          rmDirect: 686890 mills - 1455 recs/sec
          rmDirect before close(): 685484 mills - 1458 recs/sec
          btree: 706297 mills - 1415 recs/sec
          btree before close: 704719 mills - 1419 recs/sec
          rmDirect db filesize = 8230150144
          rmDirect db filesize before close() = 8221925376
          btree db filesize = 8273838080
          btree db filesize before close() = 8273838080

           
          • Kevin Day
            Kevin Day
            2005-08-01

            OK - these results are starting to back up my theory on where the performance hit is coming from.

            Basically, it is evident that insertions of small pieces of data.  I am going to propose the following as the cause:

            Appending data to pages in the RecordFile class is inneficient.  If you are storing large blocks of data (with a BPage object, or by having large data chunks inserted into the record manager), you are doing a lot of page creation, and not a lot of appending of data to existing pages.

            One thing that I've seen in the RecordFile class that may be a partial hint is the call to get(blockid).  It does a lookup in 2 hash tables, and then does a linear walk of a linked list (free) looking to see if the block id of the item in the free list is equal to the blockid being searched for.

            I'm not quite understanding why this is being done - I think the free list's purpose is to cache pages (these are record file pages - not BPage objects) - so they can be retrieved quickly if they are asked for again.

            What I'm not understanding at all is why the free list is implemented as a FIFO instead of a HashMap.  I think they are doing it that way to make so free pages can be pulled in a FIFO manner - this would have the effect of allowing the cached pages that are used most to stay in the free list (and re-used if the blockid is asked for again), so fewer disk access are needed.

            The problem, though, is that the entire free list has to be walked every single time you add a new page (which is happening quite a bit when you are doing batch inserts of small chunks of data).

            I'm wondering if it might not make sense to maintain a hashmap AND a FIFO for the free list.  This would allow quick lookups of the free items, but still give the FIFO behavior for recovering pages.

            Before I go code this, does anyone have any comments?  Maybe my thinking is completely bogus...

            Thanks!

            - K