Extremely low performance when writing to database

eitanyan · **Joined:** Tue Nov 27, 2007 8:31 am **Posts:** 5

I am having an extremely low performance when I am working with NHibernate, I am trying to write objects to the database, a single write per object (That's the scenario I need to support, I can't use batch write).
I am getting about 70 writes per seconds for a simple object (Calling the method Write(object) I've written below.

I don't think my machine or database is causing this slow performance, I've tried it on several machines.

I've attached the relevent code and mapping file,
I've tried to profile the code and I noticed that the line tx.Commit() is consuming about 90-95% of entire code runtime.
I've tried to disable second layer cache and query cache and it doesn't seem to help.

Does anyone know about this issue? is this the performance I am supposed to expect or am I doing something wrong?

NHibernate version:

1.2.1 GA

Mapping documents:

Code:

<?xml version="1.0" ?>
<hibernate-configuration  xmlns="urn:nhibernate-configuration-2.2" >
  <session-factory>
   <property name="use_reflection_optimizer">false</property>
   <property name="dialect">NHibernate.Dialect.MySQLDialect</property>
   <property name="connection.provider">NHibernate.Connection.DriverConnectionProvider</property>
   <property name="connection.driver_class">NHibernate.Driver.MySqlDataDriver</property>
   <property name="connection.connection_string">Server=localhost;Database=dotnetpersistency;User ID=root;Password=eitan1324;CharSet=utf8</property>                           
   <property name="cache.provider_class">NHibernate.Cache.NoCacheProvider</property>
   <property name="cache.use_second_level_cache">false</property>
   <property name="cache.use_query_cache">false</property>
   <property name="hbm2ddl.auto">create</property>
    <mapping file="ComplexPerson.hbm.xml" />

  </session-factory>
</hibernate-configuration>

ComplexPerson.hbm.xml

<?xml version="1.0"?>
<hibernate-mapping xmlns="urn:nhibernate-mapping-2.2" assembly="Ponos" namespace="Ponos">
  <class name="Ponos.ComplexPerson" table="COMPLEXPERSON">
  
    <id name="Name" column="Name" type="string">
      <generator class="assigned"/>
    </id>
    <property name="Age" />
    <property name="ClientId" />
    <component
        name="Address"
        insert="true"
        update="true">
      <property name="StreetNameAndNumber"/>
    </component>    
  </class>
</hibernate-mapping>

Code between sessionFactory.openSession() and session.close():

Code:

public void Write(object pono)
{
   ITransaction tx = null;
   ISession session = _sessionFactory.OpenSession();
   try
   {
      tx = session.BeginTransaction();
      object id = GetId(pono);
      if (id == null)
         return;
      session.SaveOrUpdateCopy(pono);
      tx.Commit();
   }
   catch (Exception e)
   {
      if (tx != null)
         tx.Rollback();
      throw new Exception("Can't execute write:", e);
      }
   finally
   {
      CloseSession(session);
   }
}

Name and version of the database you are using:
MySQL 5.1

paulh · **Posted:** Mon Jan 07, 2008 7:03 am

Couple of questions...

What performance are you after?
How many records are you saving in total
When you say single write per object, do you mean you want each record save to be in a separate transaction?

Second layer cache is to do with caching read performance, you can't easily cache a write.

eitanyan · **Joined:** Tue Nov 27, 2007 8:31 am **Posts:** 5

I am looking for the best performance possible, however, I am assuming that normal performance should be around 1000-2000 operations per seconds.

I've benchmarked this with 1000-3000 objects,
Yes each object is saved under different transaction,
You can see the code I've copied above.

Thanks

thomask · **Joined:** Tue Jan 09, 2007 5:24 am **Posts:** 15

Hi eitanyan - I don't know if this applies to your project, but make sure that log4net is turned off for NHibernate related namespaces.

If you don't activate log4net yourself you can assume it is not running.

Cheers,
Thomas

eitanyan · **Joined:** Tue Nov 27, 2007 8:31 am **Posts:** 5

I haven't configured log4net at all, so I am assuming it is not running.

jta · **Posted:** Tue Jan 08, 2008 11:50 am

eitanyan wrote:

Yes each object is saved under different transaction, You can see the code I've copied above.

Have you investigated where time is spent, in the database, in your code or nHibernate code.. That has to be the first step

If the time is spent in the database investigate the SQL that nHibernate generates and executes.

eitanyan · **Joined:** Tue Nov 27, 2007 8:31 am **Posts:** 5

Yes I have investigated it, I've stated above that about 90-95% of the time is spend on the tx.commit() line.

It seems a bit more complicated for me to investigate if most of the time is spent in the database it self, as I see it I must be working with NHibernate source code, and compile it in debug mode and then profile it.

Is there any easier way to check if the time is spent in the database?

Thanks
Eitan

jta · **Posted:** Wed Jan 09, 2008 5:50 am

If the tx.Commit line is taking the time i would bet its your database that is using the time and not nHibernate internals. I haven't seen a Profiler for MySQL but i have not used MySQL for a while so try to take a look around.

marcal · **Posted:** Wed Jan 09, 2008 4:55 pm

eitanyan wrote:

It seems a bit more complicated for me to investigate if most of the time is spent in the database it self, as I see it I must be working with NHibernate source code, and compile it in debug mode and then profile it.

Before that, configure log4net and dump ALL to a file. It will skew timing a bit (so don't use a console appender, those tend to be very slow). That should help show what's taking up the time. Even though it is all on Commit(), that induces NH to Flush(), which might be costly.

Also remember that every time you open and close a session you are opening and closing a DB connection. Would MySQL perform much better when directly accessed with a connection for every insert?

And yes, there are ways to span multiple sessions across a single connection.

Final note: if you are using an "assigned" generator, why SaveOrUpdateCopy() and not just Save()? Come to think of it, that could be your problem since SaveOrUpdateCopy() will initiate a query to the database for your object before inserting, since the session is empty.

SteveMc · **Joined:** Wed Aug 15, 2007 7:37 am **Posts:** 73

If you haven't already, it might be worth pulling out the SQL that Hibernate is generating and running it directly through ADO (you might need to edit it slightly, and possibly just take a few lines and loop them) - that cuts out the Hibernate end of things and should tell you what kind of overhead it's adding over talking straight to the database. Hibernate does add some overhead but on our properly configured MySQL databases the performance hit seemed to be in the realms of 10-15% for a fairly small object hierarchy (a table-per-subclass mapped object with a couple of collections).

As marcal has said, it's difficult to profile MySQL per se especially with very small operations, but it IS possible to eliminate certain parts of what you're doing.

Opening MySQL connections generally isn't too costly as it will tend to pool them by default.