Happens here too. I've narrowed it down to a simple parent/child mapping. It seems to happen only when the parent has a version property.
This is a serious problem for me: Unnecessarily updated objects cause StaleObjectExceptions for other sessions accessing them. The only workaround I found is to to fill code accessing those objects with redundant session.Refresh() calls.
Hibernate version:
1.2.0.GA
Mapping documents:
Parent class mapping:
Code:
<hibernate-mapping xmlns="urn:nhibernate-mapping-2.2" xmlns:xs="http://www.w3.org/2001/XMLSchema"
assembly="NHibParentChild"
namespace="NHibParentChild">
<class name="Parent" table="Parents">
<id name="Id" type="Int32" unsaved-value="0">
<generator class="native"/>
</id>
<!-- test passes if the following line is omitted -->
<version name="Version" unsaved-value="negative"/>
<set name="Children" inverse="true" cascade="none" lazy="true">
<key column="ParentId" />
<one-to-many class="Child" />
</set>
</class>
</hibernate-mapping>
Note that the redundant updates don't happen if the version property is removed.
Child class mapping:
Code:
<?xml version="1.0" encoding="utf-8" ?>
<hibernate-mapping xmlns="urn:nhibernate-mapping-2.2" xmlns:xs="http://www.w3.org/2001/XMLSchema"
assembly="NHibParentChild"
namespace="NHibParentChild">
<class name="Child" table="Children">
<id name="Id" type="Int32" unsaved-value="0">
<generator class="native"/>
</id>
<many-to-one name="Parent" column="ParentId" class="Parent" cascade="none" not-null="true"/>
</class>
</hibernate-mapping>
Code between sessionFactory.openSession() and session.close():This is a test which checks whether the saved Parent's version was unnecessarily incremented after saving the child.
Code:
// Create and save parent
Parent pA = new Parent();
session.Save(pA);
session.Flush();
int savedVersion = pA.Version;
Child c1 = new Child();
c1.Parent = pA;
// Test passes if the following line is omitted
pA.Children.Add(c1);
session.Save(c1);
// Test passes if the following line is omitted
session.Flush();
session.Refresh(pA);
Assert.AreEqual(savedVersion, pA.Version, "parent was updated");
Name and version of the database you are using:SQL Server 2005
The generated SQL (show_sql=true):Code:
NHibernate: INSERT INTO Parents (Version) VALUES (@p0); select SCOPE_IDENTITY(); @p0 = '1'
NHibernate: INSERT INTO Children (ParentId) VALUES (@p0); select SCOPE_IDENTITY(); @p0 = '42'
NHibernate: UPDATE Parents SET Version = @p0 WHERE Id = @p1 AND Version = @p2; @p0 = '2', @p1 = '42', @p2 = '1'
NHibernate: SELECT parent0_.Id as Id1_0_, parent0_.Version as Version1_0_ FROM Parents parent0_ WHERE parent0_.Id=@p0; @p0 = '42'
The parent's version changes for some reason. This causes the last two redundant UPDATE and SELECT statements.
Debug level Hibernate log excerpt:Code:
2007-11-19 19:13:22,234 Thread-TestRunnerThread DEBUG NHibernate.Impl.SessionImpl: opened session
2007-11-19 19:13:22,234 Thread-TestRunnerThread DEBUG NHibernate.Impl.SessionImpl: saving [NHibParentChild.Parent#<null>]
2007-11-19 19:13:22,234 Thread-TestRunnerThread DEBUG NHibernate.Impl.SessionImpl: executing insertions
2007-11-19 19:13:22,234 Thread-TestRunnerThread DEBUG NHibernate.Engine.Cascades: version unsaved-value strategy NEGATIVE
2007-11-19 19:13:22,234 Thread-TestRunnerThread DEBUG NHibernate.Engine.Versioning: Seeding: 1
2007-11-19 19:13:22,250 Thread-TestRunnerThread DEBUG NHibernate.Impl.WrapVisitor: Wrapped collection in role: NHibParentChild.Parent.Children
2007-11-19 19:13:22,250 Thread-TestRunnerThread DEBUG NHibernate.Persister.Entity.AbstractEntityPersister: Inserting entity: NHibParentChild.Parent (native id)
2007-11-19 19:13:22,250 Thread-TestRunnerThread DEBUG NHibernate.Persister.Entity.AbstractEntityPersister: Version: 1
2007-11-19 19:13:22,250 Thread-TestRunnerThread DEBUG NHibernate.Impl.BatcherImpl: Opened new IDbCommand, open IDbCommands: 1
2007-11-19 19:13:22,250 Thread-TestRunnerThread DEBUG NHibernate.Impl.BatcherImpl: Building an IDbCommand object for the SqlString: INSERT INTO Parents (Version) VALUES (?); select SCOPE_IDENTITY()
2007-11-19 19:13:22,250 Thread-TestRunnerThread DEBUG NHibernate.Persister.Entity.AbstractEntityPersister: Dehydrating entity: [NHibParentChild.Parent#<null>]
2007-11-19 19:13:22,250 Thread-TestRunnerThread DEBUG NHibernate.SQL: INSERT INTO Parents (Version) VALUES (@p0); select SCOPE_IDENTITY(); @p0 = '1'
2007-11-19 19:13:22,250 Thread-TestRunnerThread DEBUG NHibernate.Connection.DriverConnectionProvider: Obtaining IDbConnection from Driver
2007-11-19 19:13:22,265 Thread-TestRunnerThread DEBUG NHibernate.Impl.BatcherImpl: Opened IDataReader, open IDataReaders: 1
2007-11-19 19:13:22,265 Thread-TestRunnerThread DEBUG NHibernate.Persister.Entity.AbstractEntityPersister: Natively generated identity: 44
2007-11-19 19:13:22,265 Thread-TestRunnerThread DEBUG NHibernate.Driver.NHybridDataReader: running NHybridDataReader.Dispose()
2007-11-19 19:13:22,265 Thread-TestRunnerThread DEBUG NHibernate.Impl.BatcherImpl: Closed IDataReader, open IDataReaders :0
2007-11-19 19:13:22,265 Thread-TestRunnerThread DEBUG NHibernate.Impl.BatcherImpl: Closed IDbCommand, open IDbCommands: 0
2007-11-19 19:13:22,265 Thread-TestRunnerThread DEBUG NHibernate.Impl.ConnectionManager: aggressively releasing database connection
2007-11-19 19:13:22,265 Thread-TestRunnerThread DEBUG NHibernate.Connection.ConnectionProvider: Closing connection
2007-11-19 19:13:22,265 Thread-TestRunnerThread DEBUG NHibernate.Impl.SessionImpl: flushing session
2007-11-19 19:13:22,265 Thread-TestRunnerThread DEBUG NHibernate.Impl.SessionImpl: Flushing entities and processing referenced collections
2007-11-19 19:13:22,265 Thread-TestRunnerThread DEBUG NHibernate.Impl.AbstractVisitor: Processing collection for role NHibParentChild.Parent.Children
2007-11-19 19:13:22,265 Thread-TestRunnerThread DEBUG NHibernate.Impl.SessionImpl: Collection found: [NHibParentChild.Parent.Children#44], was: [<unreferenced>]
2007-11-19 19:13:22,265 Thread-TestRunnerThread DEBUG NHibernate.Impl.SessionImpl: Processing unreferenced collections
2007-11-19 19:13:22,265 Thread-TestRunnerThread DEBUG NHibernate.Impl.SessionImpl: scheduling collection removes/(re)creates/updates
2007-11-19 19:13:22,265 Thread-TestRunnerThread DEBUG NHibernate.Impl.SessionImpl: Flushed: 0 insertions, 0 updates, 0 deletions to 1 objects
2007-11-19 19:13:22,265 Thread-TestRunnerThread DEBUG NHibernate.Impl.SessionImpl: Flushed: 1 (re)creations, 0 updates, 0 removals to 1 collections
2007-11-19 19:13:22,265 Thread-TestRunnerThread DEBUG NHibernate.Impl.Printer: listing entities:
2007-11-19 19:13:22,281 Thread-TestRunnerThread DEBUG NHibernate.Impl.Printer: NHibParentChild.Parent{Version=1, Children=[], Id=44}
2007-11-19 19:13:22,281 Thread-TestRunnerThread DEBUG NHibernate.Impl.SessionImpl: executing flush
2007-11-19 19:13:22,281 Thread-TestRunnerThread DEBUG NHibernate.Impl.ConnectionManager: registering flush begin
2007-11-19 19:13:22,281 Thread-TestRunnerThread DEBUG NHibernate.Impl.ConnectionManager: registering flush end
2007-11-19 19:13:22,281 Thread-TestRunnerThread DEBUG NHibernate.Impl.ConnectionManager: aggressively releasing database connection
2007-11-19 19:13:22,281 Thread-TestRunnerThread DEBUG NHibernate.Impl.SessionImpl: post flush
2007-11-19 19:13:22,281 Thread-TestRunnerThread DEBUG NHibernate.Impl.SessionImpl: saving [NHibParentChild.Child#<null>]
2007-11-19 19:13:22,281 Thread-TestRunnerThread DEBUG NHibernate.Impl.SessionImpl: executing insertions
2007-11-19 19:13:22,281 Thread-TestRunnerThread DEBUG NHibernate.Persister.Entity.AbstractEntityPersister: Inserting entity: NHibParentChild.Child (native id)
2007-11-19 19:13:22,281 Thread-TestRunnerThread DEBUG NHibernate.Impl.BatcherImpl: Opened new IDbCommand, open IDbCommands: 1
2007-11-19 19:13:22,281 Thread-TestRunnerThread DEBUG NHibernate.Impl.BatcherImpl: Building an IDbCommand object for the SqlString: INSERT INTO Children (ParentId) VALUES (?); select SCOPE_IDENTITY()
2007-11-19 19:13:22,281 Thread-TestRunnerThread DEBUG NHibernate.Persister.Entity.AbstractEntityPersister: Dehydrating entity: [NHibParentChild.Child#<null>]
2007-11-19 19:13:22,281 Thread-TestRunnerThread DEBUG NHibernate.SQL: INSERT INTO Children (ParentId) VALUES (@p0); select SCOPE_IDENTITY(); @p0 = '44'
2007-11-19 19:13:22,281 Thread-TestRunnerThread DEBUG NHibernate.Connection.DriverConnectionProvider: Obtaining IDbConnection from Driver
2007-11-19 19:13:22,296 Thread-TestRunnerThread DEBUG NHibernate.Impl.BatcherImpl: Opened IDataReader, open IDataReaders: 1
2007-11-19 19:13:22,296 Thread-TestRunnerThread DEBUG NHibernate.Persister.Entity.AbstractEntityPersister: Natively generated identity: 17
2007-11-19 19:13:22,296 Thread-TestRunnerThread DEBUG NHibernate.Driver.NHybridDataReader: running NHybridDataReader.Dispose()
2007-11-19 19:13:22,296 Thread-TestRunnerThread DEBUG NHibernate.Impl.BatcherImpl: Closed IDataReader, open IDataReaders :0
2007-11-19 19:13:22,296 Thread-TestRunnerThread DEBUG NHibernate.Impl.BatcherImpl: Closed IDbCommand, open IDbCommands: 0
2007-11-19 19:13:22,296 Thread-TestRunnerThread DEBUG NHibernate.Impl.ConnectionManager: aggressively releasing database connection
2007-11-19 19:13:22,296 Thread-TestRunnerThread DEBUG NHibernate.Connection.ConnectionProvider: Closing connection
2007-11-19 19:13:22,296 Thread-TestRunnerThread DEBUG NHibernate.Impl.SessionImpl: flushing session
2007-11-19 19:13:22,296 Thread-TestRunnerThread DEBUG NHibernate.Impl.CollectionEntry: Collection dirty: [NHibParentChild.Parent.Children#44]
2007-11-19 19:13:22,296 Thread-TestRunnerThread DEBUG NHibernate.Impl.SessionImpl: Flushing entities and processing referenced collections
2007-11-19 19:13:22,296 Thread-TestRunnerThread DEBUG NHibernate.Impl.SessionImpl: Updating entity: [NHibParentChild.Parent#44]
2007-11-19 19:13:22,296 Thread-TestRunnerThread DEBUG NHibernate.Engine.Versioning: Incrementing: 1 to 2
2007-11-19 19:13:22,296 Thread-TestRunnerThread DEBUG NHibernate.Impl.AbstractVisitor: Processing collection for role NHibParentChild.Parent.Children
2007-11-19 19:13:22,296 Thread-TestRunnerThread DEBUG NHibernate.Impl.SessionImpl: Collection found: [NHibParentChild.Parent.Children#44], was: [NHibParentChild.Parent.Children#44]
2007-11-19 19:13:22,296 Thread-TestRunnerThread DEBUG NHibernate.Impl.SessionImpl: Processing unreferenced collections
2007-11-19 19:13:22,296 Thread-TestRunnerThread DEBUG NHibernate.Impl.SessionImpl: scheduling collection removes/(re)creates/updates
2007-11-19 19:13:22,296 Thread-TestRunnerThread DEBUG NHibernate.Impl.SessionImpl: Flushed: 0 insertions, 1 updates, 0 deletions to 2 objects
2007-11-19 19:13:22,296 Thread-TestRunnerThread DEBUG NHibernate.Impl.SessionImpl: Flushed: 0 (re)creations, 1 updates, 0 removals to 1 collections
2007-11-19 19:13:22,296 Thread-TestRunnerThread DEBUG NHibernate.Impl.Printer: listing entities:
2007-11-19 19:13:22,296 Thread-TestRunnerThread DEBUG NHibernate.Impl.Printer: NHibParentChild.Child{Parent=Parent#44, Id=17}
2007-11-19 19:13:22,296 Thread-TestRunnerThread DEBUG NHibernate.Impl.Printer: NHibParentChild.Parent{Version=1, Children=[Child#17], Id=44}
2007-11-19 19:13:22,296 Thread-TestRunnerThread DEBUG NHibernate.Impl.SessionImpl: executing flush
2007-11-19 19:13:22,296 Thread-TestRunnerThread DEBUG NHibernate.Impl.ConnectionManager: registering flush begin
2007-11-19 19:13:22,296 Thread-TestRunnerThread DEBUG NHibernate.Persister.Entity.AbstractEntityPersister: Updating entity: [NHibParentChild.Parent#44]
2007-11-19 19:13:22,296 Thread-TestRunnerThread DEBUG NHibernate.Persister.Entity.AbstractEntityPersister: Existing version: 1 -> New Version: 2
2007-11-19 19:13:22,296 Thread-TestRunnerThread DEBUG NHibernate.Impl.BatcherImpl: Opened new IDbCommand, open IDbCommands: 1
2007-11-19 19:13:22,296 Thread-TestRunnerThread DEBUG NHibernate.Impl.BatcherImpl: Building an IDbCommand object for the SqlString: UPDATE Parents SET Version = ? WHERE Id = ? AND Version = ?
2007-11-19 19:13:22,296 Thread-TestRunnerThread DEBUG NHibernate.Persister.Entity.AbstractEntityPersister: Dehydrating entity: [NHibParentChild.Parent#44]
2007-11-19 19:13:22,296 Thread-TestRunnerThread DEBUG NHibernate.SQL: UPDATE Parents SET Version = @p0 WHERE Id = @p1 AND Version = @p2; @p0 = '2', @p1 = '44', @p2 = '1'
2007-11-19 19:13:22,296 Thread-TestRunnerThread DEBUG NHibernate.Connection.DriverConnectionProvider: Obtaining IDbConnection from Driver
2007-11-19 19:13:22,296 Thread-TestRunnerThread DEBUG NHibernate.Impl.BatcherImpl: Closed IDbCommand, open IDbCommands: 0
2007-11-19 19:13:22,296 Thread-TestRunnerThread DEBUG NHibernate.Impl.ConnectionManager: skipping aggressive-release due to flush cycle
2007-11-19 19:13:22,312 Thread-TestRunnerThread DEBUG NHibernate.Impl.ConnectionManager: registering flush end
2007-11-19 19:13:22,312 Thread-TestRunnerThread DEBUG NHibernate.Impl.ConnectionManager: aggressively releasing database connection
2007-11-19 19:13:22,312 Thread-TestRunnerThread DEBUG NHibernate.Connection.ConnectionProvider: Closing connection
2007-11-19 19:13:22,312 Thread-TestRunnerThread DEBUG NHibernate.Impl.SessionImpl: post flush
2007-11-19 19:13:22,312 Thread-TestRunnerThread DEBUG NHibernate.Impl.SessionImpl: refreshing [NHibParentChild.Parent#44]
2007-11-19 19:13:22,312 Thread-TestRunnerThread DEBUG NHibernate.Impl.SessionImpl: evicting collection: [NHibParentChild.Parent.Children#44]
2007-11-19 19:13:22,328 Thread-TestRunnerThread DEBUG NHibernate.Persister.Entity.AbstractEntityPersister: Fetching entity: [NHibParentChild.Parent#44]
2007-11-19 19:13:22,328 Thread-TestRunnerThread DEBUG NHibernate.Loader.Loader: loading entity: [NHibParentChild.Parent#44]
2007-11-19 19:13:22,328 Thread-TestRunnerThread DEBUG NHibernate.Impl.BatcherImpl: Opened new IDbCommand, open IDbCommands: 1
2007-11-19 19:13:22,328 Thread-TestRunnerThread DEBUG NHibernate.Impl.BatcherImpl: Building an IDbCommand object for the SqlString: SELECT parent0_.Id as Id1_0_, parent0_.Version as Version1_0_ FROM Parents parent0_ WHERE parent0_.Id=?
2007-11-19 19:13:22,328 Thread-TestRunnerThread INFO NHibernate.Loader.Loader: SELECT parent0_.Id as Id1_0_, parent0_.Version as Version1_0_ FROM Parents parent0_ WHERE parent0_.Id=@p0
2007-11-19 19:13:22,328 Thread-TestRunnerThread DEBUG NHibernate.SQL: SELECT parent0_.Id as Id1_0_, parent0_.Version as Version1_0_ FROM Parents parent0_ WHERE parent0_.Id=@p0; @p0 = '44'
2007-11-19 19:13:22,328 Thread-TestRunnerThread DEBUG NHibernate.Connection.DriverConnectionProvider: Obtaining IDbConnection from Driver
2007-11-19 19:13:22,328 Thread-TestRunnerThread DEBUG NHibernate.Impl.BatcherImpl: Opened IDataReader, open IDataReaders: 1
2007-11-19 19:13:22,328 Thread-TestRunnerThread DEBUG NHibernate.Loader.Loader: processing result set
2007-11-19 19:13:22,328 Thread-TestRunnerThread DEBUG NHibernate.Loader.Loader: result set row: 0
2007-11-19 19:13:22,328 Thread-TestRunnerThread DEBUG NHibernate.Loader.Loader: result row: 44
2007-11-19 19:13:22,328 Thread-TestRunnerThread DEBUG NHibernate.Loader.Loader: Initializing object from DataReader: [NHibParentChild.Parent#44]
2007-11-19 19:13:22,328 Thread-TestRunnerThread DEBUG NHibernate.Loader.Loader: Hydrating entity: NHibParentChild.Parent#44
2007-11-19 19:13:22,328 Thread-TestRunnerThread DEBUG NHibernate.Impl.SessionImpl: Version: 2
2007-11-19 19:13:22,328 Thread-TestRunnerThread DEBUG NHibernate.Loader.Loader: done processing result set (1 rows)
2007-11-19 19:13:22,328 Thread-TestRunnerThread DEBUG NHibernate.Driver.NHybridDataReader: running NHybridDataReader.Dispose()
2007-11-19 19:13:22,328 Thread-TestRunnerThread DEBUG NHibernate.Impl.BatcherImpl: Closed IDataReader, open IDataReaders :0
2007-11-19 19:13:22,328 Thread-TestRunnerThread DEBUG NHibernate.Impl.BatcherImpl: Closed IDbCommand, open IDbCommands: 0
2007-11-19 19:13:22,328 Thread-TestRunnerThread DEBUG NHibernate.Impl.ConnectionManager: aggressively releasing database connection
2007-11-19 19:13:22,328 Thread-TestRunnerThread DEBUG NHibernate.Connection.ConnectionProvider: Closing connection
2007-11-19 19:13:22,328 Thread-TestRunnerThread DEBUG NHibernate.Loader.Loader: total objects hydrated: 1
2007-11-19 19:13:22,328 Thread-TestRunnerThread DEBUG NHibernate.Impl.SessionImpl: resolving associations for: [NHibParentChild.Parent#44]
2007-11-19 19:13:22,328 Thread-TestRunnerThread DEBUG NHibernate.Impl.SessionImpl: creating collection wrapper:[NHibParentChild.Parent.Children#44]
2007-11-19 19:13:22,328 Thread-TestRunnerThread DEBUG NHibernate.Impl.SessionImpl: done materializing entity [NHibParentChild.Parent#44]
2007-11-19 19:13:22,328 Thread-TestRunnerThread DEBUG NHibernate.Impl.SessionImpl: initializing non-lazy collections
2007-11-19 19:13:22,328 Thread-TestRunnerThread DEBUG NHibernate.Loader.Loader: done entity load
2007-11-19 19:13:22,343 Thread-TestRunnerThread DEBUG NHibernate.Impl.SessionImpl: running ISession.Dispose()
2007-11-19 19:13:22,343 Thread-TestRunnerThread DEBUG NHibernate.Impl.SessionImpl: closing session
2007-11-19 19:13:22,343 Thread-TestRunnerThread DEBUG NHibernate.Impl.BatcherImpl: running BatcherImpl.Dispose(true)
2007-11-19 19:13:22,343 Thread-TestRunnerThread DEBUG NHibernate.Transaction.AdoTransaction: running AdoTransaction.Dispose()