NHibernate with SQLite Insert Performance Issue

Question

I'm using NHibernate 3 with SQLite 3 (to be more precise - SQLCipher but it doesn't make sense in this case).

I have configured NHibernate like that:

<hibernate-configuration  xmlns="urn:nhibernate-configuration-2.2" >
    <session-factory>
        <property name="connection.provider">NHibernate.Connection.DriverConnectionProvider</property>
        <property name="connection.driver_class">Test.NHibernate.MySqliteDriver, nhibernate_test</property>     
        <property name="connection.connection_string">Data Source=embedded</property>
        <property name="dialect">NHibernate.Dialect.SQLiteDialect</property>
        <property name="query.substitutions">true=1;false=0</property>  
        <property name="proxyfactory.factory_class">NHibernate.ByteCode.LinFu.ProxyFactoryFactory, NHibernate.ByteCode.LinFu, Version=3.0.0.4000, Culture=neutral, PublicKeyToken=aa95f207798dfdb4</property>
        <property name="show_sql">true</property>
    </session-factory>
</hibernate-configuration>

Here, Test.NHibernate.MySqliteDriver, nhibernate_test is a custom driver that can handle connection string like Data Source=embedded. It doesn't do any specific operations except creating SQLiteConnection to memory DataSource and attaching one database to it with ATTACH instruction. It doesn't make a sense too.

I have a table:

public class Product
{
    public virtual int Id { get; set; }
    public virtual string Name { get; set; }
    public virtual string Category { get; set; }
    public virtual bool Discontinued { get; set; }
}

Mapped to:

CREATE TABLE Prosucts (
    Id INTEGER PRIMARY KEY,
    Name VARCHAR(250),
    Category VARCHAR(250),
    Discontinued INTEGER
);

With mapping:

<hibernate-mapping xmlns="urn:nhibernate-mapping-2.2" 
                   assembly="nhibernate_test" 
                   namespace="Test.NHibernate.Domain">
    <class name="Product" table="Products">
        <id name="Id">
            <generator class="native" />
        </id>
        <property name="Name" />
            <property name="Category" />
            <property name="Discontinued" />
    </class>
</hibernate-mapping>

In code i do the following:

var configuration = new Configuration();
configuration.Configure(typeof(Program).Assembly, "hibernate.cfg.xml");         
configuration.AddAssembly(typeof(Program).Assembly);

var sessionFactory = configuration.BuildSessionFactory();

var product = new Product
{
    Name = "Product",
    Category = "Products",
    Discontinued = true
};

var product2 = new Product
{
    Name = "Product 12",
    Category = "Bad products",
    Discontinued = true
};

using (var session = sessionFactory.OpenSession())
{               
    using(var transaction = session.BeginTransaction())
    {
        var sw = new Stopwatch();
        sw.Start();         

        session.Save(product);
        Console.WriteLine("saved 1st in {0}", sw.Elapsed);
        sw.Reset();
        sw.Start();

        session.Save(product2);
        Console.WriteLine("saved 2nd in {0}", sw.Elapsed);
        sw.Stop();

        transaction.Commit();
    }
}

And get a disapointing output:

NHibernate: INSERT INTO Products (Name, Category, Discontinued) VALUES (@p0, @p1 , @p2); select last_insert_rowid(); @p0 = 'Product' [Type: String (0)], @p1 = 'Products' [Type: String (0)], @p2 = True [Type: Boolean (0)]

saved 1st in 00:00:01.3444869

NHibernate: INSERT INTO Products (Name, Category, Discontinued) VALUES (@p0, @p1 , @p2); select last_insert_rowid(); @p0 = 'Product' [Type: String (0)], @p1 = 'Products' [Type: String (0)], @p2 = True [Type: Boolean (0)]

saved 2nd in 00:00:00.0044215

So why inserting 1st record takes so long??? (for 1.3 seconds)

Answer 1

I see two possible sources:

1. initializing the session cache(s) when you give it the first entity to track, and
2. SQLite firing up its internals to generate that first native identity value