NHibernate Performance Testing
From OpenSimulator
Here are results from performance tests run on SQLite and MySQL database.
Remote MySQL results with 10ms ping with MyISAM:
2009-01-01 18:02:04,664 [TestRunnerThread] INFO Example.Library.Resources.DatabaseTest [(null)] - Inserting 100 objects 2009-01-01 18:02:05,825 [TestRunnerThread] INFO Example.Library.Resources.DatabaseTest [(null)] - Took: 00:00:01.1610000 2009-01-01 18:02:05,825 [TestRunnerThread] INFO Example.Library.Resources.DatabaseTest [(null)] - Selecting 100 objects by id 2009-01-01 18:02:09,211 [TestRunnerThread] INFO Example.Library.Resources.DatabaseTest [(null)] - Took: 00:00:03.3860000 2009-01-01 18:02:09,212 [TestRunnerThread] INFO Example.Library.Resources.DatabaseTest [(null)] - Selecting 100 objects at once 2009-01-01 18:02:09,347 [TestRunnerThread] INFO Example.Library.Resources.DatabaseTest [(null)] - Took: 00:00:00.1350000 2009-01-01 18:02:09,348 [TestRunnerThread] INFO Example.Library.Resources.DatabaseTest [(null)] - Deleting 100 objects 2009-01-01 18:02:10,478 [TestRunnerThread] INFO Example.Library.Resources.DatabaseTest [(null)] - Took: 00:00:01.1300000
Local MySQL results with InnoDB:
2009-01-01 18:26:40,661 [TestRunnerThread] INFO Example.Library.Resources.DatabaseTest [(null)] - Inserting 100 objects 2009-01-01 18:26:40,718 [TestRunnerThread] INFO Example.Library.Resources.DatabaseTest [(null)] - Took: 00:00:00.0570000 2009-01-01 18:26:40,719 [TestRunnerThread] INFO Example.Library.Resources.DatabaseTest [(null)] - Selecting 100 objects by id 2009-01-01 18:26:40,766 [TestRunnerThread] INFO Example.Library.Resources.DatabaseTest [(null)] - Took: 00:00:00.0470000 2009-01-01 18:26:40,766 [TestRunnerThread] INFO Example.Library.Resources.DatabaseTest [(null)] - Selecting 100 objects at once 2009-01-01 18:26:40,858 [TestRunnerThread] INFO Example.Library.Resources.DatabaseTest [(null)] - Took: 00:00:00.0920000 2009-01-01 18:26:40,858 [TestRunnerThread] INFO Example.Library.Resources.DatabaseTest [(null)] - Deleting 100 objects 2009-01-01 18:26:40,886 [TestRunnerThread] INFO Example.Library.Resources.DatabaseTest [(null)] - Took: 00:00:00.0280000
Local MySQL results with MyISAM:
2009-01-01 18:32:20,006 [TestRunnerThread] INFO Example.Library.Resources.DatabaseTest [(null)] - Inserting 100 objects 2009-01-01 18:32:20,020 [TestRunnerThread] INFO Example.Library.Resources.DatabaseTest [(null)] - Took: 00:00:00.0120000 2009-01-01 18:32:20,020 [TestRunnerThread] INFO Example.Library.Resources.DatabaseTest [(null)] - Selecting 100 objects by id 2009-01-01 18:32:20,067 [TestRunnerThread] INFO Example.Library.Resources.DatabaseTest [(null)] - Took: 00:00:00.0470000 2009-01-01 18:32:20,068 [TestRunnerThread] INFO Example.Library.Resources.DatabaseTest [(null)] - Selecting 100 objects at once 2009-01-01 18:32:20,140 [TestRunnerThread] INFO Example.Library.Resources.DatabaseTest [(null)] - Took: 00:00:00.0720000 2009-01-01 18:32:20,140 [TestRunnerThread] INFO Example.Library.Resources.DatabaseTest [(null)] - Deleting 100 objects 2009-01-01 18:32:20,153 [TestRunnerThread] INFO Example.Library.Resources.DatabaseTest [(null)] - Took: 00:00:00.0130000
Local SQLite results:
2009-01-01 18:10:30,356 [TestRunnerThread] INFO Example.Library.Resources.DatabaseTest [(null)] - Inserting 100 objects 2009-01-01 18:10:30,406 [TestRunnerThread] INFO Example.Library.Resources.DatabaseTest [(null)] - Took: 00:00:00.0490000 2009-01-01 18:10:30,407 [TestRunnerThread] INFO Example.Library.Resources.DatabaseTest [(null)] - Selecting 100 objects by id 2009-01-01 18:10:30,450 [TestRunnerThread] INFO Example.Library.Resources.DatabaseTest [(null)] - Took: 00:00:00.0430000 2009-01-01 18:10:30,451 [TestRunnerThread] INFO Example.Library.Resources.DatabaseTest [(null)] - Selecting 100 objects at once 2009-01-01 18:10:30,520 [TestRunnerThread] INFO Example.Library.Resources.DatabaseTest [(null)] - Took: 00:00:00.0690000 2009-01-01 18:10:30,521 [TestRunnerThread] INFO Example.Library.Resources.DatabaseTest [(null)] - Deleting 100 objects 2009-01-01 18:10:30,547 [TestRunnerThread] INFO Example.Library.Resources.DatabaseTest [(null)] - Took: 00:00:00.0260000
Test test code:
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;
namespace Example.Library.Resources
{
[TestFixture]
public class DatabaseTest
{
private static readonly ILog log = LogManager.GetLogger(typeof(DatabaseTest));
private ISessionFactory sessions;
[SetUp]
public void SetUp()
{
// log4net configuration
XmlConfigurator.Configure();
//BasicConfigurator.Configure();
// hibernate configuration
Configuration configuration = new Configuration();
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);
}
foreach(String key in configuration.Properties.Keys)
{
log.Info(key+": "+configuration.Properties[key]);
}
sessions = configuration.BuildSessionFactory();
}
[Test]
public void TestDatabase()
{
using (IStatelessSession session = sessions.OpenStatelessSession())
{
using (ITransaction transaction = session.BeginTransaction())
{
TestObject newObject = new TestObject();
newObject.TestId = Guid.NewGuid();
newObject.Name = "test-name";
session.Insert(newObject);
TestObject loadedObject = (TestObject)session.Get("Example.Library.Resources.TestObject", newObject.TestId);
Assert.AreEqual(newObject.Name,loadedObject.Name);
session.Delete(loadedObject);
transaction.Commit();
}
}
}
[Test]
public void TestDatabasePerformance()
{
int objectCount = 100;
List<TestObject> testObjects = new List<TestObject>();
DateTime timeStamp;
log.Info("Inserting " + objectCount + " objects");
timeStamp = DateTime.Now;
using (IStatelessSession session = sessions.OpenStatelessSession())
{
using (ITransaction transaction = session.BeginTransaction())
{
for (int i = 0; i < objectCount; i++)
{
TestObject newObject = new TestObject();
newObject.TestId = Guid.NewGuid();
newObject.Name = "test-name";
session.Insert(newObject);
testObjects.Add(newObject);
}
transaction.Commit();
}
}
log.Info("Took: " + DateTime.Now.Subtract(timeStamp));
timeStamp = DateTime.Now;
log.Info("Selecting " + objectCount + " objects by id");
using (IStatelessSession session = sessions.OpenStatelessSession())
{
for (int i = 0; i < objectCount; 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;
}
}
log.Info("Took: " + DateTime.Now.Subtract(timeStamp));
timeStamp = DateTime.Now;
log.Info("Selecting " + objectCount + " objects at once");
using (IStatelessSession session = sessions.OpenStatelessSession())
{
IQuery q = session.CreateQuery("from Example.Library.Resources.TestObject");
IList loadedObjects = q.List();
foreach (TestObject testObject in loadedObjects)
{
}
Assert.AreEqual(objectCount, testObjects.Count);
}
log.Info("Took: " + DateTime.Now.Subtract(timeStamp));
timeStamp = DateTime.Now;
log.Info("Deleting " + objectCount + " objects");
using (IStatelessSession session = sessions.OpenStatelessSession())
{
using (ITransaction transaction = session.BeginTransaction())
{
for (int i = 0; i < objectCount; i++)
{
TestObject loadedObject = testObjects[i];
session.Delete(loadedObject);
}
transaction.Commit();
}
}
log.Info("Took: " + DateTime.Now.Subtract(timeStamp));
timeStamp = DateTime.Now;
}
}
}
The configuration for the test dll:
<?xml version="1.0" encoding="utf-8" ?>
<configuration>
<configSections>
<section name="hibernate-configuration" type="NHibernate.Cfg.ConfigurationSectionHandler, NHibernate" />
<section name="log4net" type="log4net.Config.Log4NetConfigurationSectionHandler, log4net" />
</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">
<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>
