NonUniqueObjectException error inserting multiple rows, LAST_INSERT_ID() returns 0

Question

I am using NHibernate/Fluent NHibernate in an ASP.NET MVC app with a MySQL database. I am working on an operation that reads quite a bit of data (relative to how much is inserted), processes it, and ends up inserting (currently) about 50 records. I have one ISession per request which is created/destroyed in the begin/end request event handlers (exactly like like http://ayende.com/Blog/archive/2009/08/06/challenge-find-the-bug-fixes.aspx), and I am reading in data and adding new objects (as in section 16.3 at https://www.hibernate.org/hib_docs/nhibernate/html/example-parentchild.html), and finally calling Flush() on the session to actually run all the inserts.

Getting data out and lazy loading work fine, and when I call Flush exactly 2 new records are being inserted (I am manually checking the table to find this out), and then I get the following error:

NonUniqueObjectException: a different object with the same identifier value was already associated with the session: 0, of entity: ...

I am new to NHibernate and while searching for a solution have tried explicitly setting the Id property's generator to both Native and Identity (it is a MySQL database and the Id column is an int with auto_increment on), and explicitly setting the unsaved value for the Id property to 0. I still get the error, however.

I have also tried calling Flush at different times (effectively once per INSERT) and I then get the same error, but for an identity value other than 0 and at seemingly random points in the process (sometimes I do not get it at all in this scenario, but sometimes I do at different points).

I am not sure where to go from here. Any help or insight would be greatly appreciated.

EDIT: See the answer below.

Answer 1

EDIT: I originally posted a different "answer" that did not actually solve the problem, but I want to document my findings here for anyone else who may come across it.

After several days of trying to figure out the problem and resolve this issue, and being extremely frustrated because the issue seemed to go away for awhile and then come back intermittently (causing me to think multiple times that a change I made fixed it, when in fact it did not), I believe I have tracked down the real issue.

A few times after I turned the log4net level for NHibernate up to DEBUG, the problem went away, but I was finally able to get the error with that log level. Included in the log were these lines:

Building an IDbCommand object for the SqlString: SELECT LAST_INSERT_ID()
...
NHibernate.Type.Int32Type: 15:10:36 [8] DEBUG NHibernate.Type.Int32Type: returning '0' as column: LAST_INSERT_ID()
NHibernate.Id.IdentifierGeneratorFactory: 15:10:36 [8] DEBUG NHibernate.Id.IdentifierGeneratorFactory: 
Natively generated identity: 0

And looking up just a few lines I saw:

NHibernate.AdoNet.ConnectionManager: 15:10:36 [8] DEBUG NHibernate.AdoNet.ConnectionManager: aggressively releasing database connection
NHibernate.Connection.ConnectionProvider: 15:10:36 [8] DEBUG NHibernate.Connection.ConnectionProvider: Closing connection

It seems that while flushing the session and performing INSERTs, NHibernate was closing the connection between the INSERT statement and the "SELECT LAST_INSERT_ID()" to get the id that was generated by MySQL for the INSERT statement. Or rather, I should say it was sometimes closing the connection which is one reason I believe the problem was intermittent. I can't find the link now, but I believe I also read in all my searching that MySQL will sometimes return the correct value from LAST_INSERT_ID() even if the connection is closed and reopened, which is another reason I believe it was intermittent. Most of the time, though, LAST_INSERT_ID() will return 0 if the connection is closed and reopened after the INSERT.

It appears there are 2 ways to go about fixing this issue. First is a patch available here that looks like it will make it into NHibernate 2.1.1, or which you can use to make your own build of NHibernate, which forces the INSERT and SELECT LAST_INSERT_ID() to run together. Second, you can set the connection.release_mode to on_close as described in this blog post which prevents NHibernate from closing the connection until the ISession is explicitly closed.

I took the latter approach, which is done in FluentNHibernate like this:

Fluently.Configure()
    ...
    .ExposeConfiguration(c => c.Properties.Add("connection.release_mode", "on_close"))
    ...

This also had the side effect of drastically speeding up my code. What was taking 20-30 seconds to run (when it just so happened to work before I made this change) is now running in 7-10 seconds, so it is doing the same work in ~1/3 the time.