NHibernate Performance Testing

From OpenSimulator

(Difference between revisions)
Jump to: navigation, search
m
m (Removed 'Template:' prefix from template includings and/or changed external-link into internal-link)
 
(18 intermediate revisions by 2 users not shown)
Line 1: Line 1:
Here are results from NHibernate performance tests run on SQLite and MySQL database. In the test 1000 rows are inserted, updated, selected and deletes against tables with 0 and 10000 rows initially. Remote MySQL is added to demonstrate the network lag effect when batch operations are not used (It seems NHibernate does not support batch inserts, updates and deletes for MySQL). Some background information:
+
__NOTOC__
 +
{{Quicklinks}}
 +
<br />
 +
 
 +
Here are results from NHibernate performance tests run on SQLite and MySQL database.  
  
 
* Local machine is Windows Vista 64 bit with Quad Core processor and 4G memory. MySQL has factory settings.
 
* Local machine is Windows Vista 64 bit with Quad Core processor and 4G memory. MySQL has factory settings.
* Remote mysql database machine is Ubuntu Linux virtual machine with one virtual processor and 2G memory. MySQL has factory settings.
+
* Remote MySQL database machine is Ubuntu Linux virtual machine with one virtual processor and 2G memory. MySQL has factory settings.
 
* Local machine ping is 10 ms to the remote machine.
 
* Local machine ping is 10 ms to the remote machine.
 +
* There are no other clients loading the database and this comparison does not reflect reliably to real load with mutiple simultaneous connections.
 
* Performance test is execute with NAnt and .NET-framework 2.0.
 
* Performance test is execute with NAnt and .NET-framework 2.0.
  
 
+
In the first test 1000 rows are inserted, updated, selected and deleted against tables with 0 and 10000 rows initially. Remote MySQL is added to demonstrate the network lag effect when batch operations are not used. NHibernate does not support batch inserts, updates and deletes in combination with MySQL. According to the results MySQL with MyISAM has best performance:
Note: There are no other clients loading the database and this comparison does not reflect reliably to real load with mutiple simultaneous connections.
+
 
+
 
+
According to the results MySQL with MyISAM performs best. Surprisingly MySQL seems to perform better when there are 10000 rows in the database:
+
  
 
[[Image:nhibernate_performance_test.png]]
 
[[Image:nhibernate_performance_test.png]]
  
== Results with Initially Empty Tables ==
+
=== Local MySQL/MyISAM Versus SQLite Comparison ===
  
=== Remote MySQL results with MyISAM ===
+
Here is more in depth comparison with local MyISAM and SQLite using 1000 test objects and variable amount of initial objects varying from 1 to 1 000 000. SQLite insert and delete performance degrades almost linearly.
  
<pre>
+
[[Image:mysql_sqlite_performance_comparison.png]]
2009-01-01 19:31:21,796 [TestRunnerThread] INFO  Example.Library.Resources.DatabaseTest [(null)] - Dialect: NHibernate.Dialect.MySQL5Dialect
+
2009-01-01 19:33:19,216 [TestRunnerThread] INFO  Example.Library.Resources.DatabaseTest [(null)] - Inserting 1000 objects to table with 0 initial objects.
+
2009-01-01 19:33:30,623 [TestRunnerThread] INFO  Example.Library.Resources.DatabaseTest [(null)] - Took: 00:00:11.4070000
+
2009-01-01 19:33:30,624 [TestRunnerThread] INFO  Example.Library.Resources.DatabaseTest [(null)] - Updating 1000 objects to table with 0 initial objects.
+
2009-01-01 19:33:53,526 [TestRunnerThread] INFO  Example.Library.Resources.DatabaseTest [(null)] - Took: 00:00:22.9030000
+
2009-01-01 19:33:53,528 [TestRunnerThread] INFO  Example.Library.Resources.DatabaseTest [(null)] - Selecting 1000 objects by id from table with 0 initial objects.
+
2009-01-01 19:34:37,263 [TestRunnerThread] INFO  Example.Library.Resources.DatabaseTest [(null)] - Took: 00:00:43.7350000
+
2009-01-01 19:34:37,264 [TestRunnerThread] INFO  Example.Library.Resources.DatabaseTest [(null)] - Selecting 1000 objects at once from table with 0 initial objects.
+
2009-01-01 19:34:37,383 [TestRunnerThread] INFO  Example.Library.Resources.DatabaseTest [(null)] - Took: 00:00:00.1190000
+
2009-01-01 19:34:37,384 [TestRunnerThread] INFO  Example.Library.Resources.DatabaseTest [(null)] - Deleting 1000 objects from table with 0 initial objects.
+
2009-01-01 19:34:48,952 [TestRunnerThread] INFO  Example.Library.Resources.DatabaseTest [(null)] - Took: 00:00:11.5680000
+
</pre>
+
  
=== Local MySQL results with InnoDB ===
+
=== Local MySQL/MyISAM Analysis ===
  
<pre>
+
As mentioned before NHibernate does not support batch inserts, updated and deletes when used in combination with MySQL. As a result the per object execution time is bound by network delay even in local installations as illustrated below. Without session recycling serial updates of 30 or more objects at once gives 4 times better performance.
2009-01-01 19:44:26,425 [TestRunnerThread] INFO  Example.Library.Resources.DatabaseTest [(null)] - Dialect: NHibernate.Dialect.MySQL5Dialect
+
2009-01-01 19:44:28,267 [TestRunnerThread] INFO  Example.Library.Resources.DatabaseTest [(null)] - Inserting 1000 objects to table with 10000 initial objects.
+
2009-01-01 19:44:28,429 [TestRunnerThread] INFO  Example.Library.Resources.DatabaseTest [(null)] - Took: 00:00:00.1620000
+
2009-01-01 19:44:28,429 [TestRunnerThread] INFO  Example.Library.Resources.DatabaseTest [(null)] - Updating 1000 objects to table with 10000 initial objects.
+
2009-01-01 19:44:28,799 [TestRunnerThread] INFO  Example.Library.Resources.DatabaseTest [(null)] - Took: 00:00:00.3700000
+
2009-01-01 19:44:28,800 [TestRunnerThread] INFO  Example.Library.Resources.DatabaseTest [(null)] - Selecting 1000 objects by id from table with 10000 initial objects.
+
2009-01-01 19:44:29,209 [TestRunnerThread] INFO  Example.Library.Resources.DatabaseTest [(null)] - Took: 00:00:00.4090000
+
2009-01-01 19:44:29,210 [TestRunnerThread] INFO  Example.Library.Resources.DatabaseTest [(null)] - Selecting 1000 objects at once from table with 10000 initial objects.
+
2009-01-01 19:44:29,226 [TestRunnerThread] INFO  Example.Library.Resources.DatabaseTest [(null)] - Took: 00:00:00.0160000
+
2009-01-01 19:44:29,226 [TestRunnerThread] INFO  Example.Library.Resources.DatabaseTest [(null)] - Deleting 1000 objects from table with 10000 initial objects.
+
2009-01-01 19:44:29,358 [TestRunnerThread] INFO  Example.Library.Resources.DatabaseTest [(null)] - Took: 00:00:00.1320000
+
</pre>
+
  
=== Local MySQL results with MyISAM ===
+
[[Image:mysql_performance.png]]
  
<pre>
+
With session recycling there is only transaction cost to win which yields 2 times better performance when updating 30 or more objects at once.
2009-01-01 19:46:08,213 [TestRunnerThread] INFO  Example.Library.Resources.DatabaseTest [(null)] - Dialect: NHibernate.Dialect.MySQL5Dialect
+
2009-01-01 19:46:11,436 [TestRunnerThread] INFO  Example.Library.Resources.DatabaseTest [(null)] - Inserting 1000 objects to table with 10000 initial objects.
+
2009-01-01 19:46:11,550 [TestRunnerThread] INFO  Example.Library.Resources.DatabaseTest [(null)] - Took: 00:00:00.1120000
+
2009-01-01 19:46:11,552 [TestRunnerThread] INFO  Example.Library.Resources.DatabaseTest [(null)] - Updating 1000 objects to table with 10000 initial objects.
+
2009-01-01 19:46:11,868 [TestRunnerThread] INFO  Example.Library.Resources.DatabaseTest [(null)] - Took: 00:00:00.3160000
+
2009-01-01 19:46:11,870 [TestRunnerThread] INFO  Example.Library.Resources.DatabaseTest [(null)] - Selecting 1000 objects by id from table with 10000 initial objects.
+
2009-01-01 19:46:12,295 [TestRunnerThread] INFO  Example.Library.Resources.DatabaseTest [(null)] - Took: 00:00:00.4250000
+
2009-01-01 19:46:12,296 [TestRunnerThread] INFO  Example.Library.Resources.DatabaseTest [(null)] - Selecting 1000 objects at once from table with 10000 initial objects.
+
2009-01-01 19:46:12,313 [TestRunnerThread] INFO  Example.Library.Resources.DatabaseTest [(null)] - Took: 00:00:00.0170000
+
2009-01-01 19:46:12,315 [TestRunnerThread] INFO  Example.Library.Resources.DatabaseTest [(null)] - Deleting 1000 objects from table with 10000 initial objects.
+
2009-01-01 19:46:12,456 [TestRunnerThread] INFO  Example.Library.Resources.DatabaseTest [(null)] - Took: 00:00:00.1410000
+
</pre>
+
  
=== Local SQLite results ===
+
[[Image:mysql_performance_no_session_recycling.png]]
  
<pre>
+
The update and individual select operations were most expensive with 400 microseconds cost per object.
2009-01-01 19:30:14,206 [TestRunnerThread] INFO  Example.Library.Resources.DatabaseTest [(null)] - Dialect: NHibernate.Dialect.SQLiteDialect
+
2009-01-01 19:30:14,923 [TestRunnerThread] INFO  Example.Library.Resources.DatabaseTest [(null)] - Inserting 1000 objects to table with 0 initial objects.
+
2009-01-01 19:30:15,169 [TestRunnerThread] INFO  Example.Library.Resources.DatabaseTest [(null)] - Took: 00:00:00.2460000
+
2009-01-01 19:30:15,169 [TestRunnerThread] INFO  Example.Library.Resources.DatabaseTest [(null)] - Updating 1000 objects to table with 0 initial objects.
+
2009-01-01 19:30:15,391 [TestRunnerThread] INFO  Example.Library.Resources.DatabaseTest [(null)] - Took: 00:00:00.2220000
+
2009-01-01 19:30:15,391 [TestRunnerThread] INFO  Example.Library.Resources.DatabaseTest [(null)] - Selecting 1000 objects by id from table with 0 initial objects.
+
2009-01-01 19:30:15,871 [TestRunnerThread] INFO  Example.Library.Resources.DatabaseTest [(null)] - Took: 00:00:00.4800000
+
2009-01-01 19:30:15,872 [TestRunnerThread] INFO  Example.Library.Resources.DatabaseTest [(null)] - Selecting 1000 objects at once from table with 0 initial objects.
+
2009-01-01 19:30:15,891 [TestRunnerThread] INFO  Example.Library.Resources.DatabaseTest [(null)] - Took: 00:00:00.0190000
+
2009-01-01 19:30:15,891 [TestRunnerThread] INFO  Example.Library.Resources.DatabaseTest [(null)] - Deleting 1000 objects from table with 0 initial objects.
+
2009-01-01 19:30:15,937 [TestRunnerThread] INFO  Example.Library.Resources.DatabaseTest [(null)] - Took: 00:00:00.0460000
+
</pre>
+
  
== Results with Tables Containing Initially 10000 Rows ==
+
Inserts and deletes had 200 microseconds cost due to the lack of indexing work required. Only primary key (id) index had to be updated.
  
=== Remote MySQL results with MyISAM ===
+
Fastest were mass select which measured only the streaming speed from the database and ended up with 10 microseconds cost per object.
  
<pre>
+
As conclusion MySQL performance with table sizes up to 1M of rows were not bound by table size dependent operations but factors like network delay and data transfer rate between application and database.
2009-01-01 19:38:17,164 [TestRunnerThread] INFO  Example.Library.Resources.DatabaseTest [(null)] - Dialect: NHibernate.Dialect.MySQL5Dialect
+
2009-01-01 19:40:12,072 [TestRunnerThread] INFO  Example.Library.Resources.DatabaseTest [(null)] - Inserting 1000 objects to table with 10000 initial objects.
+
2009-01-01 19:40:23,514 [TestRunnerThread] INFO  Example.Library.Resources.DatabaseTest [(null)] - Took: 00:00:11.4420000
+
2009-01-01 19:40:23,514 [TestRunnerThread] INFO  Example.Library.Resources.DatabaseTest [(null)] - Updating 1000 objects to table with 10000 initial objects.
+
2009-01-01 19:40:46,659 [TestRunnerThread] INFO  Example.Library.Resources.DatabaseTest [(null)] - Took: 00:00:23.1450000
+
2009-01-01 19:40:46,660 [TestRunnerThread] INFO  Example.Library.Resources.DatabaseTest [(null)] - Selecting 1000 objects by id from table with 10000 initial objects.
+
2009-01-01 19:41:29,235 [TestRunnerThread] INFO  Example.Library.Resources.DatabaseTest [(null)] - Took: 00:00:42.5750000
+
2009-01-01 19:41:29,236 [TestRunnerThread] INFO  Example.Library.Resources.DatabaseTest [(null)] - Selecting 1000 objects at once from table with 10000 initial objects.
+
2009-01-01 19:41:29,367 [TestRunnerThread] INFO  Example.Library.Resources.DatabaseTest [(null)] - Took: 00:00:00.1310000
+
2009-01-01 19:41:29,367 [TestRunnerThread] INFO  Example.Library.Resources.DatabaseTest [(null)] - Deleting 1000 objects from table with 10000 initial objects.
+
2009-01-01 19:41:40,746 [TestRunnerThread] INFO  Example.Library.Resources.DatabaseTest [(null)] - Took: 00:00:11.3790000
+
</pre>
+
 
+
=== Local MySQL results with InnoDB ===
+
 
+
<pre>
+
2009-01-01 19:17:44,493 [TestRunnerThread] INFO  Example.Library.Resources.DatabaseTest [(null)] - Inserting 100 objects.
+
2009-01-01 19:17:44,525 [TestRunnerThread] INFO  Example.Library.Resources.DatabaseTest [(null)] - Took: 00:00:00.0200000
+
2009-01-01 19:17:44,525 [TestRunnerThread] INFO  Example.Library.Resources.DatabaseTest [(null)] - Updating 100 objects.
+
2009-01-01 19:17:44,591 [TestRunnerThread] INFO  Example.Library.Resources.DatabaseTest [(null)] - Took: 00:00:00.0660000
+
2009-01-01 19:17:44,592 [TestRunnerThread] INFO  Example.Library.Resources.DatabaseTest [(null)] - Selecting 100 objects by id.
+
2009-01-01 19:17:44,642 [TestRunnerThread] INFO  Example.Library.Resources.DatabaseTest [(null)] - Took: 00:00:00.0500000
+
2009-01-01 19:17:44,643 [TestRunnerThread] INFO  Example.Library.Resources.DatabaseTest [(null)] - Selecting 100 objects at once.
+
2009-01-01 19:17:44,649 [TestRunnerThread] INFO  Example.Library.Resources.DatabaseTest [(null)] - Took: 00:00:00.0060000
+
2009-01-01 19:17:44,649 [TestRunnerThread] INFO  Example.Library.Resources.DatabaseTest [(null)] - Deleting 100 objects.
+
2009-01-01 19:17:44,675 [TestRunnerThread] INFO  Example.Library.Resources.DatabaseTest [(null)] - Took: 00:00:00.0260000
+
</pre>
+
 
+
=== Local MySQL results with MyISAM ===
+
 
+
<pre>
+
2009-01-01 19:20:07,657 [TestRunnerThread] INFO  Example.Library.Resources.DatabaseTest [(null)] - Inserting 100 objects.
+
2009-01-01 19:20:07,683 [TestRunnerThread] INFO  Example.Library.Resources.DatabaseTest [(null)] - Took: 00:00:00.0130000
+
2009-01-01 19:20:07,685 [TestRunnerThread] INFO  Example.Library.Resources.DatabaseTest [(null)] - Updating 100 objects.
+
2009-01-01 19:20:07,727 [TestRunnerThread] INFO  Example.Library.Resources.DatabaseTest [(null)] - Took: 00:00:00.0420000
+
2009-01-01 19:20:07,728 [TestRunnerThread] INFO  Example.Library.Resources.DatabaseTest [(null)] - Selecting 100 objects by id.
+
2009-01-01 19:20:07,774 [TestRunnerThread] INFO  Example.Library.Resources.DatabaseTest [(null)] - Took: 00:00:00.0460000
+
2009-01-01 19:20:07,776 [TestRunnerThread] INFO  Example.Library.Resources.DatabaseTest [(null)] - Selecting 100 objects at once.
+
2009-01-01 19:20:07,781 [TestRunnerThread] INFO  Example.Library.Resources.DatabaseTest [(null)] - Took: 00:00:00.0050000
+
2009-01-01 19:20:07,782 [TestRunnerThread] INFO  Example.Library.Resources.DatabaseTest [(null)] - Deleting 100 objects.
+
2009-01-01 19:20:07,799 [TestRunnerThread] INFO  Example.Library.Resources.DatabaseTest [(null)] - Took: 00:00:00.0170000
+
</pre>
+
 
+
=== Local SQLite results ===
+
 
+
<pre>
+
2009-01-01 19:47:14,320 [TestRunnerThread] INFO  Example.Library.Resources.DatabaseTest [(null)] - Dialect: NHibernate.Dialect.SQLiteDialect
+
2009-01-01 19:47:15,469 [TestRunnerThread] INFO  Example.Library.Resources.DatabaseTest [(null)] - Inserting 1000 objects to table with 10000 initial objects.
+
2009-01-01 19:47:15,881 [TestRunnerThread] INFO  Example.Library.Resources.DatabaseTest [(null)] - Took: 00:00:00.4120000
+
2009-01-01 19:47:15,882 [TestRunnerThread] INFO  Example.Library.Resources.DatabaseTest [(null)] - Updating 1000 objects to table with 10000 initial objects.
+
2009-01-01 19:47:16,138 [TestRunnerThread] INFO  Example.Library.Resources.DatabaseTest [(null)] - Took: 00:00:00.2560000
+
2009-01-01 19:47:16,138 [TestRunnerThread] INFO  Example.Library.Resources.DatabaseTest [(null)] - Selecting 1000 objects by id from table with 10000 initial objects.
+
2009-01-01 19:47:16,619 [TestRunnerThread] INFO  Example.Library.Resources.DatabaseTest [(null)] - Took: 00:00:00.4810000
+
2009-01-01 19:47:16,619 [TestRunnerThread] INFO  Example.Library.Resources.DatabaseTest [(null)] - Selecting 1000 objects at once from table with 10000 initial objects.
+
2009-01-01 19:47:16,639 [TestRunnerThread] INFO  Example.Library.Resources.DatabaseTest [(null)] - Took: 00:00:00.0200000
+
2009-01-01 19:47:16,640 [TestRunnerThread] INFO  Example.Library.Resources.DatabaseTest [(null)] - Deleting 1000 objects from table with 10000 initial objects.
+
2009-01-01 19:47:17,042 [TestRunnerThread] INFO  Example.Library.Resources.DatabaseTest [(null)] - Took: 00:00:00.4020000
+
</pre>
+
  
 
== Performance Test Code and Configuration ==
 
== Performance Test Code and Configuration ==
Line 149: Line 44:
  
 
<pre>
 
<pre>
 +
using System;
 
using System;
 
using System;
 
using System.Collections.Generic;
 
using System.Collections.Generic;
Line 161: Line 57:
 
using log4net.Config;
 
using log4net.Config;
 
using System.Collections;
 
using System.Collections;
 +
using Example.Library.Resources;
  
namespace Example.Library.Resources
+
namespace Example.Library
 
{
 
{
  
Line 168: Line 65:
 
     public class DatabasePerformanceTest
 
     public class DatabasePerformanceTest
 
     {
 
     {
         private static readonly ILog log = LogManager.GetLogger(typeof(DatabaseTest));
+
         private static readonly ILog log = LogManager.GetLogger(typeof(DatabasePerformanceTest));
        private ISessionFactory sessions;
+
        private const int INITIAL_OBJECT_COUNT = 10000;
+
        private const int TEST_OBJECT_COUNT = 1000;
+
  
 
         [SetUp]
 
         [SetUp]
 
         public void SetUp()
 
         public void SetUp()
 
         {
 
         {
            // log4net configuration
 
 
             XmlConfigurator.Configure();  
 
             XmlConfigurator.Configure();  
 +
        }
 +
 +
        [Test]
 +
        public void TestDatabasePerformance()
 +
        {
 +
 +
            IList<DatabasePerformanceResult> mysqlResults=new List<DatabasePerformanceResult>();
 +
            IList<DatabasePerformanceResult> sqliteResults = new List<DatabasePerformanceResult>();
 +
 +
            for (int i = 1; i <= 10000000; i *= 10)
 +
            {
 +
                mysqlResults.Add(PerformanceTest("hibernate-mysql.cfg.xml", i, 1000));
 +
                sqliteResults.Add(PerformanceTest("hibernate-sqlite.cfg.xml", i, 1000));
 +
            }
 +
 +
            log.Info(" ;mysql-insert;sqlite-insert;mysql-update;sqlite-update;mysql-select;sqlite-select;mysql-mass select;sqlite-mass select;mysql-delete;sqlite-delete");
 +
            for (int i = 0; i < mysqlResults.Count; i++)
 +
            {
 +
                log.Info(
 +
                    mysqlResults[i].Name + ";" +
 +
                    mysqlResults[i].InsertTime + ";" +
 +
                    sqliteResults[i].InsertTime + ";" +
 +
                    mysqlResults[i].UpdateTime + ";" +
 +
                    sqliteResults[i].UpdateTime + ";" +
 +
                    mysqlResults[i].SelectTime + ";" +
 +
                    sqliteResults[i].SelectTime + ";" +
 +
                    mysqlResults[i].MassSelectTime + ";" +
 +
                    sqliteResults[i].MassSelectTime + ";" +
 +
                    mysqlResults[i].DeleteTime + ";" +
 +
                    sqliteResults[i].DeleteTime
 +
                    );
 +
            }
 +
        }
 +
 +
        public DatabasePerformanceResult PerformanceTest(String configurationFileName, int initialObjectCount, int testObjectCount)
 +
        {
 +
            DatabasePerformanceResult result = new DatabasePerformanceResult();
 +
 +
            result.Name = initialObjectCount.ToString();
  
            // hibernate configuration
 
 
             Configuration configuration = new Configuration();
 
             Configuration configuration = new Configuration();
 +
            configuration.Configure(configurationFileName);
 
             configuration.AddAssembly(this.GetType().Assembly);
 
             configuration.AddAssembly(this.GetType().Assembly);
                       
+
 
             if (configuration.Properties["dialect"].Equals("NHibernate.Driver.SQLite20Driver")&&
+
             if (configuration.Properties["dialect"].Equals("NHibernate.Driver.SQLite20Driver") &&
 
                 !File.Exists("OpenSimExample.db"))
 
                 !File.Exists("OpenSimExample.db"))
 
             {
 
             {
Line 192: Line 124:
 
             log.Info("Dialect: " + configuration.Properties["dialect"]);
 
             log.Info("Dialect: " + configuration.Properties["dialect"]);
  
             sessions = configuration.BuildSessionFactory();
+
             ISessionFactory sessionFactory = configuration.BuildSessionFactory();
  
             using (IStatelessSession session = sessions.OpenStatelessSession())
+
             using (IStatelessSession session = sessionFactory.OpenStatelessSession())
 
             {
 
             {
 
                 using (ITransaction transaction = session.BeginTransaction())
 
                 using (ITransaction transaction = session.BeginTransaction())
Line 211: Line 143:
 
                 using (ITransaction transaction = session.BeginTransaction())
 
                 using (ITransaction transaction = session.BeginTransaction())
 
                 {
 
                 {
                     for (int i = 0; i < INITIAL_OBJECT_COUNT; i++)
+
                     for (int i = 0; i < initialObjectCount; i++)
 
                     {
 
                     {
 
                         TestObject newObject = new TestObject();
 
                         TestObject newObject = new TestObject();
Line 223: Line 155:
  
 
             }
 
             }
        }
 
  
        [Test]
 
        public void TestDatabasePerformance()
 
        {
 
           
 
 
             List<TestObject> testObjects = new List<TestObject>();
 
             List<TestObject> testObjects = new List<TestObject>();
 
             DateTime timeStamp;
 
             DateTime timeStamp;
  
             log.Info("Inserting " + TEST_OBJECT_COUNT + " objects to table with " + INITIAL_OBJECT_COUNT + " initial objects.");
+
             log.Info("Inserting " + testObjectCount + " objects to table with " + initialObjectCount + " initial objects.");
  
 
             timeStamp = DateTime.Now;
 
             timeStamp = DateTime.Now;
             using (IStatelessSession session = sessions.OpenStatelessSession())
+
             using (IStatelessSession session = sessionFactory.OpenStatelessSession())
 
             {
 
             {
  
Line 241: Line 168:
 
                 {
 
                 {
  
                     for (int i = 0; i < TEST_OBJECT_COUNT; i++)
+
                     for (int i = 0; i < testObjectCount; i++)
 
                     {
 
                     {
 
                         TestObject newObject = new TestObject();
 
                         TestObject newObject = new TestObject();
Line 253: Line 180:
 
                     transaction.Commit();
 
                     transaction.Commit();
 
                 }
 
                 }
           
+
 
 
             }
 
             }
  
             log.Info("Took: " + DateTime.Now.Subtract(timeStamp));
+
            result.InsertTime = DateTime.Now.Subtract(timeStamp).TotalSeconds;
 +
             log.Info("Took: " + result.InsertTime);
 
             timeStamp = DateTime.Now;
 
             timeStamp = DateTime.Now;
             log.Info("Updating " + TEST_OBJECT_COUNT + " objects to table with " + INITIAL_OBJECT_COUNT + " initial objects.");
+
             log.Info("Updating " + testObjectCount + " objects to table with " + initialObjectCount + " initial objects.");
  
             using (IStatelessSession session = sessions.OpenStatelessSession())
+
             using (IStatelessSession session = sessionFactory.OpenStatelessSession())
 
             {
 
             {
 
                 using (ITransaction transaction = session.BeginTransaction())
 
                 using (ITransaction transaction = session.BeginTransaction())
 
                 {
 
                 {
  
                     for (int i = 0; i < TEST_OBJECT_COUNT; i++)
+
                     for (int i = 0; i < testObjectCount; i++)
 
                     {
 
                     {
 
                         TestObject oldObject = testObjects[i];
 
                         TestObject oldObject = testObjects[i];
Line 279: Line 207:
 
             }
 
             }
  
             log.Info("Took: " + DateTime.Now.Subtract(timeStamp));
+
            result.UpdateTime = DateTime.Now.Subtract(timeStamp).TotalSeconds;
 +
             log.Info("Took: " + result.UpdateTime);
 
             timeStamp = DateTime.Now;
 
             timeStamp = DateTime.Now;
             log.Info("Selecting " + TEST_OBJECT_COUNT + " objects by id from table with " + INITIAL_OBJECT_COUNT + " initial objects.");
+
             log.Info("Selecting " + testObjectCount + " objects by id from table with " + initialObjectCount + " initial objects.");
  
             using (IStatelessSession session = sessions.OpenStatelessSession())
+
             using (IStatelessSession session = sessionFactory.OpenStatelessSession())
 
             {
 
             {
  
                 for (int i = 0; i < TEST_OBJECT_COUNT; i++)
+
                 for (int i = 0; i < testObjectCount; i++)
 
                 {
 
                 {
 
                     TestObject oldObject = testObjects[i];
 
                     TestObject oldObject = testObjects[i];
Line 298: Line 227:
 
             }
 
             }
  
             log.Info("Took: " + DateTime.Now.Subtract(timeStamp));
+
            result.SelectTime = DateTime.Now.Subtract(timeStamp).TotalSeconds;
 +
             log.Info("Took: " + result.SelectTime);
 
             timeStamp = DateTime.Now;
 
             timeStamp = DateTime.Now;
             log.Info("Selecting " + TEST_OBJECT_COUNT + " objects at once from table with " + INITIAL_OBJECT_COUNT + " initial objects.");
+
             log.Info("Selecting " + testObjectCount + " objects at once from table with " + initialObjectCount + " initial objects.");
  
             using (IStatelessSession session = sessions.OpenStatelessSession())
+
             using (IStatelessSession session = sessionFactory.OpenStatelessSession())
 
             {
 
             {
  
 
                 IQuery q = session.CreateQuery("from Example.Library.Resources.TestObject");
 
                 IQuery q = session.CreateQuery("from Example.Library.Resources.TestObject");
                 q.SetMaxResults(TEST_OBJECT_COUNT);
+
                 q.SetMaxResults(testObjectCount);
  
 
                 IList loadedObjects = q.List();
 
                 IList loadedObjects = q.List();
Line 313: Line 243:
 
                 {
 
                 {
 
                     // Make sure object is not lazy loaded.
 
                     // Make sure object is not lazy loaded.
                     Guid id = testObject.TestId;
+
                     Guid objectId = testObject.TestId;
                     String name = testObject.Name;
+
                     String objectName = testObject.Name;
 
                 }
 
                 }
  
                 Assert.AreEqual(TEST_OBJECT_COUNT, testObjects.Count);
+
                 Assert.AreEqual(testObjectCount, testObjects.Count);
  
 
             }
 
             }
  
             log.Info("Took: " + DateTime.Now.Subtract(timeStamp));
+
            result.MassSelectTime = DateTime.Now.Subtract(timeStamp).TotalSeconds;
 +
             log.Info("Took: " + result.MassSelectTime);
 
             timeStamp = DateTime.Now;
 
             timeStamp = DateTime.Now;
             log.Info("Deleting " + TEST_OBJECT_COUNT + " objects from table with " + INITIAL_OBJECT_COUNT + " initial objects.");
+
             log.Info("Deleting " + testObjectCount + " objects from table with " + initialObjectCount + " initial objects.");
  
             using (IStatelessSession session = sessions.OpenStatelessSession())
+
             using (IStatelessSession session = sessionFactory.OpenStatelessSession())
 
             {
 
             {
  
Line 331: Line 262:
 
                 {
 
                 {
  
                     for (int i = 0; i < TEST_OBJECT_COUNT; i++)
+
                     for (int i = 0; i < testObjectCount; i++)
 
                     {
 
                     {
  
Line 345: Line 276:
 
             }
 
             }
  
             log.Info("Took: " + DateTime.Now.Subtract(timeStamp));
+
            result.DeleteTime = DateTime.Now.Subtract(timeStamp).TotalSeconds;
 +
             log.Info("Took: " + result.DeleteTime);
 
             timeStamp = DateTime.Now;
 
             timeStamp = DateTime.Now;
  
 +
            return result;
 
         }
 
         }
 +
 
     }
 
     }
 +
 +
    public struct DatabasePerformanceResult
 +
    {
 +
        public String Name;
 +
        public double InsertTime;
 +
        public double UpdateTime;
 +
        public double SelectTime;
 +
        public double MassSelectTime;
 +
        public double DeleteTime;
 +
    }
 +
 +
   
 +
 
}
 
}
 
</pre>
 
</pre>
Line 415: Line 362:
  
 
   <configSections>     
 
   <configSections>     
    <section name="hibernate-configuration" type="NHibernate.Cfg.ConfigurationSectionHandler, NHibernate" />
 
 
     <section name="log4net" type="log4net.Config.Log4NetConfigurationSectionHandler, log4net" />
 
     <section name="log4net" type="log4net.Config.Log4NetConfigurationSectionHandler, log4net" />
 
   </configSections>
 
   </configSections>
 
  <hibernate-configuration xmlns="urn:nhibernate-configuration-2.2">
 
 
    <!--
 
    <session-factory>
 
      <property name="connection.provider">NHibernate.Connection.DriverConnectionProvider</property>
 
      <property name="connection.driver_class">NHibernate.Driver.SQLite20Driver</property>
 
      <property name="connection.connection_string">
 
        Data Source=OpenSimExample.db;Version=3
 
      </property>
 
      <property name="dialect">NHibernate.Dialect.SQLiteDialect</property>
 
      <property name="query.substitutions">true=1;false=0</property>
 
      <property name="show_sql">false</property>
 
    </session-factory>
 
    -->
 
 
    <session-factory>
 
     
 
      <property name="connection.provider">
 
        NHibernate.Connection.DriverConnectionProvider, NHibernate
 
      </property>
 
      <property name="connection.connection_string">
 
        Server=server;Database=database;User ID=user;Password=password
 
      </property>
 
      <property name="dialect">NHibernate.Dialect.MySQL5Dialect</property>
 
 
    </session-factory>
 
   
 
  </hibernate-configuration>
 
  
 
   <log4net debug="false">
 
   <log4net debug="false">
Line 469: Line 386:
  
 
   </log4net>
 
   </log4net>
 
  
 
</configuration>
 
</configuration>
 +
</pre>
 +
 +
MySQL hibernate configuration file:
 +
 +
<pre>
 +
<?xml version='1.0' encoding='utf-8'?>
 +
<hibernate-configuration xmlns="urn:nhibernate-configuration-2.2">
 +
  <session-factory>
 +
    <!-- properties -->
 +
    <property name="connection.driver_class">NHibernate.Driver.MySqlDataDriver</property>
 +
    <property name="connection.provider">NHibernate.Connection.DriverConnectionProvider</property>
 +
    <property name="connection.connection_string">Server=localhost;Database=operator;User ID=operator;Password=operator</property>
 +
    <property name="dialect">NHibernate.Dialect.MySQL5Dialect</property>
 +
    <property name="show_sql">false</property>
 +
  </session-factory>
 +
</hibernate-configuration>
 +
</pre>
 +
 +
SQLite hibernate configuration file:
 +
 +
<pre>
 +
<?xml version='1.0' encoding='utf-8'?>
 +
<hibernate-configuration xmlns="urn:nhibernate-configuration-2.2">
 +
  <session-factory>
 +
    <!-- properties -->
 +
      <property name="connection.provider">NHibernate.Connection.DriverConnectionProvider</property>
 +
      <property name="connection.driver_class">NHibernate.Driver.SQLite20Driver</property>
 +
      <property name="connection.connection_string">Data Source=OpenSimExample.db;Version=3</property>
 +
      <property name="dialect">NHibernate.Dialect.SQLiteDialect</property>
 +
      <property name="query.substitutions">true=1;false=0</property>
 +
      <property name="show_sql">false</property>
 +
  </session-factory>
 +
</hibernate-configuration>
 
</pre>
 
</pre>

Latest revision as of 15:11, 10 June 2011


Here are results from NHibernate performance tests run on SQLite and MySQL database.

  • Local machine is Windows Vista 64 bit with Quad Core processor and 4G memory. MySQL has factory settings.
  • Remote MySQL database machine is Ubuntu Linux virtual machine with one virtual processor and 2G memory. MySQL has factory settings.
  • Local machine ping is 10 ms to the remote machine.
  • There are no other clients loading the database and this comparison does not reflect reliably to real load with mutiple simultaneous connections.
  • Performance test is execute with NAnt and .NET-framework 2.0.

In the first test 1000 rows are inserted, updated, selected and deleted against tables with 0 and 10000 rows initially. Remote MySQL is added to demonstrate the network lag effect when batch operations are not used. NHibernate does not support batch inserts, updates and deletes in combination with MySQL. According to the results MySQL with MyISAM has best performance:

Nhibernate performance test.png

[edit] Local MySQL/MyISAM Versus SQLite Comparison

Here is more in depth comparison with local MyISAM and SQLite using 1000 test objects and variable amount of initial objects varying from 1 to 1 000 000. SQLite insert and delete performance degrades almost linearly.

Mysql sqlite performance comparison.png

[edit] Local MySQL/MyISAM Analysis

As mentioned before NHibernate does not support batch inserts, updated and deletes when used in combination with MySQL. As a result the per object execution time is bound by network delay even in local installations as illustrated below. Without session recycling serial updates of 30 or more objects at once gives 4 times better performance.

Mysql performance.png

With session recycling there is only transaction cost to win which yields 2 times better performance when updating 30 or more objects at once.

Mysql performance no session recycling.png

The update and individual select operations were most expensive with 400 microseconds cost per object.

Inserts and deletes had 200 microseconds cost due to the lack of indexing work required. Only primary key (id) index had to be updated.

Fastest were mass select which measured only the streaming speed from the database and ended up with 10 microseconds cost per object.

As conclusion MySQL performance with table sizes up to 1M of rows were not bound by table size dependent operations but factors like network delay and data transfer rate between application and database.

[edit] Performance Test Code and Configuration

NUnit test code:

using System;
using System;
using System.Collections.Generic;
using System.Text;
using NUnit.Framework;
using NHibernate;
using NHibernate.Cfg;
using System.IO;
using NHibernate.Tool.hbm2ddl;
using log4net.Repository.Hierarchy;
using log4net;
using log4net.Config;
using System.Collections;
using Example.Library.Resources;

namespace Example.Library
{

    [TestFixture]
    public class DatabasePerformanceTest
    {
        private static readonly ILog log = LogManager.GetLogger(typeof(DatabasePerformanceTest));

        [SetUp]
        public void SetUp()
        {
            XmlConfigurator.Configure(); 
        }

        [Test]
        public void TestDatabasePerformance()
        {

            IList<DatabasePerformanceResult> mysqlResults=new List<DatabasePerformanceResult>();
            IList<DatabasePerformanceResult> sqliteResults = new List<DatabasePerformanceResult>();

            for (int i = 1; i <= 10000000; i *= 10)
            {
                mysqlResults.Add(PerformanceTest("hibernate-mysql.cfg.xml", i, 1000));
                sqliteResults.Add(PerformanceTest("hibernate-sqlite.cfg.xml", i, 1000));
            }

            log.Info(" ;mysql-insert;sqlite-insert;mysql-update;sqlite-update;mysql-select;sqlite-select;mysql-mass select;sqlite-mass select;mysql-delete;sqlite-delete");
            for (int i = 0; i < mysqlResults.Count; i++) 
            {
                log.Info(
                    mysqlResults[i].Name + ";" +
                    mysqlResults[i].InsertTime + ";" +
                    sqliteResults[i].InsertTime + ";" +
                    mysqlResults[i].UpdateTime + ";" +
                    sqliteResults[i].UpdateTime + ";" +
                    mysqlResults[i].SelectTime + ";" +
                    sqliteResults[i].SelectTime + ";" +
                    mysqlResults[i].MassSelectTime + ";" +
                    sqliteResults[i].MassSelectTime + ";" +
                    mysqlResults[i].DeleteTime + ";" +
                    sqliteResults[i].DeleteTime
                    );
            }
        }

        public DatabasePerformanceResult PerformanceTest(String configurationFileName, int initialObjectCount, int testObjectCount)
        {
            DatabasePerformanceResult result = new DatabasePerformanceResult();

            result.Name = initialObjectCount.ToString();

            Configuration configuration = new Configuration();
            configuration.Configure(configurationFileName);
            configuration.AddAssembly(this.GetType().Assembly);

            if (configuration.Properties["dialect"].Equals("NHibernate.Driver.SQLite20Driver") &&
                !File.Exists("OpenSimExample.db"))
            {
                SchemaExport schemaExport = new SchemaExport(configuration);
                schemaExport.Create(true, true);
            }

            log.Info("Dialect: " + configuration.Properties["dialect"]);

            ISessionFactory sessionFactory = configuration.BuildSessionFactory();

            using (IStatelessSession session = sessionFactory.OpenStatelessSession())
            {
                using (ITransaction transaction = session.BeginTransaction())
                {
                    IQuery q = session.CreateQuery("from Example.Library.Resources.TestObject");
                    IList loadedObjects = q.List();

                    foreach (TestObject testObject in loadedObjects)
                    {
                        session.Delete(testObject);
                    }

                    transaction.Commit();
                }

                using (ITransaction transaction = session.BeginTransaction())
                {
                    for (int i = 0; i < initialObjectCount; i++)
                    {
                        TestObject newObject = new TestObject();
                        newObject.TestId = Guid.NewGuid();
                        newObject.Name = "test-object-" + i;
                        session.Insert(newObject);
                    }

                    transaction.Commit();
                }

            }

            List<TestObject> testObjects = new List<TestObject>();
            DateTime timeStamp;

            log.Info("Inserting " + testObjectCount + " objects to table with " + initialObjectCount + " initial objects.");

            timeStamp = DateTime.Now;
            using (IStatelessSession session = sessionFactory.OpenStatelessSession())
            {

                using (ITransaction transaction = session.BeginTransaction())
                {

                    for (int i = 0; i < testObjectCount; i++)
                    {
                        TestObject newObject = new TestObject();
                        newObject.TestId = Guid.NewGuid();
                        newObject.Name = "test-object-" + i;
                        session.Insert(newObject);

                        testObjects.Add(newObject);
                    }

                    transaction.Commit();
                }

            }

            result.InsertTime = DateTime.Now.Subtract(timeStamp).TotalSeconds;
            log.Info("Took: " + result.InsertTime);
            timeStamp = DateTime.Now;
            log.Info("Updating " + testObjectCount + " objects to table with " + initialObjectCount + " initial objects.");

            using (IStatelessSession session = sessionFactory.OpenStatelessSession())
            {
                using (ITransaction transaction = session.BeginTransaction())
                {

                    for (int i = 0; i < testObjectCount; i++)
                    {
                        TestObject oldObject = testObjects[i];

                        TestObject loadedObject = (TestObject)session.Get("Example.Library.Resources.TestObject", oldObject.TestId);
                        session.Update(loadedObject);

                    }

                    transaction.Commit();
                }

            }

            result.UpdateTime = DateTime.Now.Subtract(timeStamp).TotalSeconds;
            log.Info("Took: " + result.UpdateTime);
            timeStamp = DateTime.Now;
            log.Info("Selecting " + testObjectCount + " objects by id from table with " + initialObjectCount + " initial objects.");

            using (IStatelessSession session = sessionFactory.OpenStatelessSession())
            {

                for (int i = 0; i < testObjectCount; i++)
                {
                    TestObject oldObject = testObjects[i];

                    TestObject loadedObject = (TestObject)session.Get("Example.Library.Resources.TestObject", oldObject.TestId);
                    Assert.AreEqual(oldObject.Name, loadedObject.Name);
                    testObjects[i] = loadedObject;

                }

            }

            result.SelectTime = DateTime.Now.Subtract(timeStamp).TotalSeconds;
            log.Info("Took: " + result.SelectTime);
            timeStamp = DateTime.Now;
            log.Info("Selecting " + testObjectCount + " objects at once from table with " + initialObjectCount + " initial objects.");

            using (IStatelessSession session = sessionFactory.OpenStatelessSession())
            {

                IQuery q = session.CreateQuery("from Example.Library.Resources.TestObject");
                q.SetMaxResults(testObjectCount);

                IList loadedObjects = q.List();

                foreach (TestObject testObject in loadedObjects)
                {
                    // Make sure object is not lazy loaded.
                    Guid objectId = testObject.TestId;
                    String objectName = testObject.Name;
                }

                Assert.AreEqual(testObjectCount, testObjects.Count);

            }

            result.MassSelectTime = DateTime.Now.Subtract(timeStamp).TotalSeconds;
            log.Info("Took: " + result.MassSelectTime);
            timeStamp = DateTime.Now;
            log.Info("Deleting " + testObjectCount + " objects from table with " + initialObjectCount + " initial objects.");

            using (IStatelessSession session = sessionFactory.OpenStatelessSession())
            {

                using (ITransaction transaction = session.BeginTransaction())
                {

                    for (int i = 0; i < testObjectCount; i++)
                    {


                        TestObject loadedObject = testObjects[i];
                        session.Delete(loadedObject);

                    }

                    transaction.Commit();
                }

            }

            result.DeleteTime = DateTime.Now.Subtract(timeStamp).TotalSeconds;
            log.Info("Took: " + result.DeleteTime);
            timeStamp = DateTime.Now;

            return result;
        }

    }

    public struct DatabasePerformanceResult
    {
        public String Name;
        public double InsertTime;
        public double UpdateTime;
        public double SelectTime;
        public double MassSelectTime;
        public double DeleteTime;
    }

    

}

Value object code:

using System;
using System.Collections.Generic;
using System.Text;

namespace Example.Library.Resources
{
    /// <summary>
    /// Object for database tests.
    /// </summary>
    public class TestObject
    {
        private Guid testId=Guid.Empty;
        public Guid TestId {
            get
            {
                return testId;
            }
            set
            {
                testId = value;
            }
        }

        private String name;
        public String Name {
            get
            {
                return name;
            }
            set
            {
                name = value;
            }
        }
    }
}

Mapping configuration:

<?xml version="1.0" encoding="utf-8" ?>
<hibernate-mapping xmlns="urn:nhibernate-mapping-2.2">
    <class name="Example.Library.Resources.TestObject, Example.Library" table="test_object" lazy="false">
        <id name="TestId" column="TestId" type="Guid"> 
            <generator class="assigned" /> 
        </id> 
        <property name="Name" type="String" length="45" />
    </class>
</hibernate-mapping>

The configuration for the test dll:

<?xml version="1.0" encoding="utf-8" ?>
<configuration>

  <configSections>    
    <section name="log4net" type="log4net.Config.Log4NetConfigurationSectionHandler, log4net" />
  </configSections>

  <log4net debug="false">
    
    <appender name="ColoredConsoleAppender" type="log4net.Appender.ColoredConsoleAppender">
      <mapping>
        <level value="ERROR" />
        <foreColor value="White" />
        <backColor value="Red, HighIntensity" />
      </mapping>
      <layout type="log4net.Layout.PatternLayout">
        <conversionPattern value="%date [%thread] %-5level %logger [%property{NDC}] - %message%newline" />
      </layout>
    </appender>
    <root>
      <priority value="ERROR" />
      <appender-ref ref="ColoredConsoleAppender" />
    </root>
    <logger name="Example.Library">
      <level value="INFO" />
    </logger>

  </log4net>

</configuration>

MySQL hibernate configuration file:

<?xml version='1.0' encoding='utf-8'?>
<hibernate-configuration xmlns="urn:nhibernate-configuration-2.2">
  <session-factory>
    <!-- properties -->
    <property name="connection.driver_class">NHibernate.Driver.MySqlDataDriver</property>
    <property name="connection.provider">NHibernate.Connection.DriverConnectionProvider</property>
    <property name="connection.connection_string">Server=localhost;Database=operator;User ID=operator;Password=operator</property>
    <property name="dialect">NHibernate.Dialect.MySQL5Dialect</property>
    <property name="show_sql">false</property>
  </session-factory>
</hibernate-configuration>

SQLite hibernate configuration file:

<?xml version='1.0' encoding='utf-8'?>
<hibernate-configuration xmlns="urn:nhibernate-configuration-2.2">
  <session-factory>
    <!-- properties -->
      <property name="connection.provider">NHibernate.Connection.DriverConnectionProvider</property>
      <property name="connection.driver_class">NHibernate.Driver.SQLite20Driver</property>
      <property name="connection.connection_string">Data Source=OpenSimExample.db;Version=3</property>
      <property name="dialect">NHibernate.Dialect.SQLiteDialect</property>
      <property name="query.substitutions">true=1;false=0</property>
      <property name="show_sql">false</property>
  </session-factory>
</hibernate-configuration>
Personal tools
General
About This Wiki