NHibernate: Testing The Performance Urban Legend

At the end of yesterdays internal study group meeting, the organizer mentioned that I would be giving a presentation on NHibernate the following week. I plan to give a simple dog and pony show of persisting a simple object to the database and all of the setup needed to accomplish the task.

One of the participants asked for a brief description of NHibernate. I explained that it is an ORM framework (Object Relational Mapping). I expanded a bit by saying that NHibernate removes the dependency between your domain objects and your relational database by handling mapping from one to the other.

After a couple more questions it was determined that NHibernate generates SQL and is therefore inferior to stored procedures. It was the general feeling that stored procedures were the be all end all for performance and optimization. I attempted to explain that NHibernate generates parameterized queries which have all the advantages of cached query plans that stored procedures do. By this time the meeting was breaking up and I had a mission.

I wanted to challenge the dogmatic urban legend passed down from .NET developer to .NET developer since the classic ASP days. That dogma simply states you should always access your database via stored procedure for "performance reasons". Inline SQL is BAAAAAAD.

So I fired up Visual Studio, created a class and started writing tests.

The first thing I wanted to do was to create a baseline. I created a User table in a fresh SQLExpress database and wrote a test to pop 1000 rows into it in the crustiest "I just read my first Wrox book" way I could think of. I added some timing code and let it rip. The test looks like this:

[Test]
public void Time_Inline_Inserts_To_User_Table()
{
    DateTime start = DateTime.Now;

    using (SqlConnection c = new SqlConnection(connectionString))
    {
        c.Open();
        for (int i = 0; i < INSERT_COUNT; i++)
        {
            using (SqlCommand co = new SqlCommand())
            {
                co.Connection = c;
                co.CommandText =
                    "INSERT INTO dbo.Users "
                    + "(Handle, FirstName, LastName, Password, EmailAddress, LastLogon) "
                    + "VALUES ("
                    + "'UserHandle" + i + "',"
                    + "'UserFirstName" + i + "',"
                    + "'UserLastName" + i + "',"
                    + "'UserPassword" + i + "',"
                    + "'User" + i + "@email.com',"
                    + DateTime.Now.ToShortDateString() + ")";

                co.ExecuteNonQuery();
            }
        }
        c.Close();
    }
    DateTime end = DateTime.Now;
    TimeSpan time = end - start;

    Console.WriteLine(
        string.Format("{0} milliseconds to run {1} inserts by inline query",
        time.TotalMilliseconds, INSERT_COUNT));
}

From a fresh load of my test assembly into MbUnit, this code takes 1312.5 milliseconds to run 1000 inserts. Running the test repeatedly drops the time to 437.5 miliseconds. It appears that SQL Server does some optimizations for inline inserts regardless of what the tribe tells me.

Next up, I wanted to see if parameterizing the query would improve the performance. The test case looks like this:

[Test]
public void Time_Parameterized_Query_Inserts_To_User_Table()
{
    DateTime start = DateTime.Now;

    using (SqlConnection c = new SqlConnection(connectionString))
    {
        c.Open();
        for (int i = 0; i < INSERT_COUNT; i++)
        {
            using (SqlCommand co = new SqlCommand())
            {
                co.Connection = c;
                co.CommandText =
                    "INSERT INTO dbo.Users (Handle, FirstName, LastName, Password, EmailAddress, LastLogon) VALUES (@p1,@p2,@p3,@p4,@p5,@p6)";
                co.CommandType = System.Data.CommandType.Text;
                co.Parameters.AddWithValue("@p1", "UserHandle" + i);
                co.Parameters.AddWithValue("@p2", "UserFirstName" + i);
                co.Parameters.AddWithValue("@p3", "UserLastName" + i);
                co.Parameters.AddWithValue("@p4", "UserPassword" + i);
                co.Parameters.AddWithValue("@p5", "User" + i + "@email.com");
                SqlParameter param = new SqlParameter("@p6", SqlDbType.DateTime);
                param.Value = new DateTime(2000, 1, 1);
                co.Parameters.Add(param);

                co.ExecuteNonQuery();

            }
        }
        c.Close();
    }

    DateTime end = DateTime.Now;
    TimeSpan time = end - start;

    Console.WriteLine(
        string.Format("{0} milliseconds to run {1} inserts by parameterized query",
            time.TotalMilliseconds, INSERT_COUNT));

}

This test runs in 1296.9 milliseconds on a fresh load of my test assembly. Repeated runs drops the test run to ~350 milliseconds a slight advantage over the inline query. I imagine this gap would widen with a more complex query.

Finally, we have the acclaimed SQL Stored Procedure dogmatic method of how everything should be done! The stored procedure in the code below is pretty much exactly what you expect it to be.

[Test]
public void Time_Stored_Proceedure_Inserts_To_User_Table()
{
    DateTime start = DateTime.Now;

    using (SqlConnection c = new SqlConnection(connectionString))
    {
        c.Open();
        for (int i = 0; i < INSERT_COUNT; i++)
        {
            using (SqlCommand co = new SqlCommand())
            {
                co.Connection = c;
                co.CommandText = "AddUser";
                co.CommandType = CommandType.StoredProcedure;
                co.Parameters.AddWithValue("@p1", "UserHandle" + i);
                co.Parameters.AddWithValue("@p2", "UserFirstName" + i);
                co.Parameters.AddWithValue("@p3", "UserLastName" + i);
                co.Parameters.AddWithValue("@p4", "UserPassword" + i);
                co.Parameters.AddWithValue("@p5", "User" + i + "@email.com");
                SqlParameter param = new SqlParameter("@p6", SqlDbType.DateTime);
                param.Value = new DateTime(2000, 1, 1);
                co.Parameters.Add(param);

                co.ExecuteNonQuery();

            }
        }
        c.Close();
    }

    DateTime end = DateTime.Now;
    TimeSpan time = end - start;

    Console.WriteLine(
        string.Format("{0} milliseconds to run {1} inserts by stored proceedure",
            time.TotalMilliseconds, INSERT_COUNT));

}

This test runs unexpectedly in 1390.6ms. This seems like quite a long time for a stored procedure that is stored in the database and from my understanding with a query plan in place. Subsequent executions of the test yield execution times ~320ms. Just to verify this, I closed the MbUnit test runner application and reran these tests. I got the same results.

Now that we have a baseline of the various direct SQL methods that are well accepted in the .NET community, I want to see how NHibernate performs at these tasks. I see two methods available though NHibernate spinning up a session and cramming User objects into its Save() method and adding a transaction into the mix.

My first NHibernate test looks like this:

[Test]
public void Time_NHibernate_Inserts_To_User_Table()
{
    DateTime start = DateTime.Now;
    using (ISession session = factory.OpenSession())
    {
        for (int i = 0; i < INSERT_COUNT; i++)
        {
            User u = new User();
            u.Handle = "UserHandle" + i;
            u.FirstName = "UserFirstName" + i;
            u.LastName = "UserLastName" + i;
            u.Password = "UserPassword" + i;
            u.EmailAddress = "User" + i + "@email.com";
            u.LastLogon = DateTime.Now;

            session.Save(u);

        }
        session.Close();

    }

    DateTime end = DateTime.Now;
    TimeSpan time = end - start;

    Console.WriteLine(
        string.Format("{0} milliseconds to run {1} inserts by nhibernate",
            time.TotalMilliseconds, INSERT_COUNT));

}

This test runs in 1656.3ms with reruns clocking in at ~560ms. It looks like NHibernate might have a slight performance hit when compared to stored procedures.

My last test using NHibernate transactions looks like this:

[Test]
public void Time_NHibernate_Tansaction_Inserts_To_User_Table()
{
    DateTime start = DateTime.Now;
    using (ISession session = factory.OpenSession())
    {

        ITransaction transaction = session.BeginTransaction();
        for (int i = 0; i < INSERT_COUNT; i++)
        {
            User u = new User();
            u.Handle = "UserHandle" + i;
            u.FirstName = "UserFirstName" + i;
            u.LastName = "UserLastName" + i;
            u.Password = "UserPassword" + i;
            u.EmailAddress = "User" + i + "@email.com";
            u.LastLogon = DateTime.Now;

            session.Save(u);

        }
        transaction.Commit();
        session.Close();

    }

    DateTime end = DateTime.Now;
    TimeSpan time = end - start;

    Console.WriteLine(
        string.Format("{0} milliseconds to run {1} inserts by nhibernate with transaction",
            time.TotalMilliseconds, INSERT_COUNT));

}

This test runs in 1406.3ms with follow up runs in 300ms. A dramatic increase in performance over over the non transactional processing. So the final performance test results looks something like this:

  <td valign="top" width="82">__1st Run__</td>

  <td valign="top" width="77">__nth Run__</td>
</tr>

<tr>
  <td valign="top" width="227">Inline SQL</td>

  <td valign="top" width="87">1312.5ms</td>

  <td valign="top" width="82">~430ms</td>
</tr>

<tr>
  <td valign="top" width="222">Parameterized Query</td>

  <td valign="top" width="91">1296.9ms</td>

  <td valign="top" width="85">~350ms</td>
</tr>

<tr>
  <td valign="top" width="217">Stored Procedure</td>

  <td valign="top" width="94">1390.6ms</td>

  <td valign="top" width="87">~320ms</td>
</tr>

<tr>
  <td valign="top" width="214">NHibernate</td>

  <td valign="top" width="96">1565.3ms</td>

  <td valign="top" width="88">~560ms</td>
</tr>

<tr>
  <td valign="top" width="212">NHibernate w/Transaction</td>

  <td valign="top" width="97">1406.3ms</td>

  <td valign="top" width="88">~300ms</td>
</tr>
__Test__

I am not going to try to interpret these results, but simply publish them and see what feedback I get from the collective. My next steps are to increase the complexity of what I am doing; add some joins into the mix. I want to see if the performance gap widens or a clear winner emerges.

If you would like to see the entire code base for these tests, I have published them to my CodePlex repository and would love to hear your ideas on squeezing out performance with both SQL and NHibernate. Look for the NHibTester solution.

Follow me on Mastodon!