Hibernate Community • View topic - Transient problem: Bidirectional cascade all-delete-orphan

View unanswered posts | View active topics

Board index » Hibernate & Java Persistence » Hibernate Users

All times are UTC - 5 hours [ DST ]

Transient problem: Bidirectional cascade all-delete-orphan

Page 1 of 1

[ 3 posts ]

Previous topic | Next topic

Author

Message

abCOGhi1

Post subject: Transient problem: Bidirectional cascade all-delete-orphan

Posted: Fri Jan 05, 2007 12:30 pm

Newbie

Joined: Fri Jan 05, 2007 8:34 am
Posts: 3

I'm getting a TransientObjectException when I'm trying to persist a graph of objects for the first time. This started after I added the cascade="all-delete-orphan". Perhaps this is due to the cycle of object references?

ObjectRoot has a list of the As and the Bs. As refers to a B. B has a set of As.

Any help would be appreciated.

Hibernate version: 3.2.1

Mapping documents:

Code:

<hibernate-mapping>
  <class name="hibtest.ObjectRoot" table="ObjectRoot">
    <id name="id" column="object_root_id" access="field">
      <generator class="native"/>
    </id>
    <list name="aList" table="A" access="field" cascade="all-delete-orphan" lazy="false">
        <key column="object_root_id"/>
   <list-index column="a_index"/>
   <one-to-many class="hibtest.A"/>
    </list>
    <list name="bList" table="B" access="field" cascade="all-delete-orphan" lazy="false">
        <key column="object_root_id"/>
   <list-index column="b_index"/>
   <one-to-many class="hibtest.B"/>
    </list>
  </class>
</hibernate-mapping>

Code:

<hibernate-mapping>
  <class name="hibtest.A" table="A">
    <id name="id" column="a_id" access="field">
      <generator class="native"/>
    </id>
    <property name="name" access="field"/>
    <many-to-one name="b" column="b_id" access="field" cascade="all" lazy="false"/>
  </class>
</hibernate-mapping>

Code:

<hibernate-mapping>
  <class name="hibtest.B" table="B">
    <id name="id" column="b_id" access="field">
      <generator class="native"/>
    </id>
    <set name="aList" table="A" access="field" cascade="all-delete-orphan" lazy="false" inverse="true">
        <key column="b_id"/>
   <one-to-many class="hibtest.A"/>
    </set>
  </class>
</hibernate-mapping>

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

Code:

ObjectRoot objectRoot = new ObjectRoot();
List<A> aList = objectRoot.getAList();
List<B> bList = objectRoot.getBList();
A a1 = new A("a1");
A a2 = new A("a2");
A a3 = new A("a3");
B b1 = new B("b1");
a1.setB(b1);
a2.setB(b1);
a3.setB(b1);

aList.add(a1);
aList.add(a2);
aList.add(a3);
bList.add(b1);

Session session = sessionFactory.getCurrentSession();
session.beginTransaction();

session.saveOrUpdate(objectRoot);

session.getTransaction().commit();

Full stack trace of any exception that occurs:

Code:

Exception in thread "main" org.hibernate.TransientObjectException: object references an unsaved transient instance - save the transient instance before flushing: hibtest.A
   at org.hibernate.engine.ForeignKeys.getEntityIdentifierIfNotUnsaved(ForeignKeys.java:219)
   at org.hibernate.collection.AbstractPersistentCollection.getOrphans(AbstractPersistentCollection.java:889)
   at org.hibernate.collection.PersistentSet.getOrphans(PersistentSet.java:90)
   at org.hibernate.engine.CollectionEntry.getOrphans(CollectionEntry.java:350)
   at org.hibernate.engine.Cascade.deleteOrphans(Cascade.java:340)
   at org.hibernate.engine.Cascade.cascadeCollectionElements(Cascade.java:324)
   at org.hibernate.engine.Cascade.cascadeCollection(Cascade.java:242)
   at org.hibernate.engine.Cascade.cascadeAssociation(Cascade.java:219)
   at org.hibernate.engine.Cascade.cascadeProperty(Cascade.java:169)
   at org.hibernate.engine.Cascade.cascade(Cascade.java:130)
   at org.hibernate.event.def.AbstractSaveEventListener.cascadeAfterSave(AbstractSaveEventListener.java:437)
   at org.hibernate.event.def.AbstractSaveEventListener.performSaveOrReplicate(AbstractSaveEventListener.java:326)
   at org.hibernate.event.def.AbstractSaveEventListener.performSave(AbstractSaveEventListener.java:180)
   at org.hibernate.event.def.AbstractSaveEventListener.saveWithGeneratedId(AbstractSaveEventListener.java:108)
   at org.hibernate.event.def.DefaultSaveOrUpdateEventListener.saveWithGeneratedOrRequestedId(DefaultSaveOrUpdateEventListener.java:186)
   at org.hibernate.event.def.DefaultSaveOrUpdateEventListener.entityIsTransient(DefaultSaveOrUpdateEventListener.java:175)
   at org.hibernate.event.def.DefaultSaveOrUpdateEventListener.performSaveOrUpdate(DefaultSaveOrUpdateEventListener.java:98)
   at org.hibernate.event.def.DefaultSaveOrUpdateEventListener.onSaveOrUpdate(DefaultSaveOrUpdateEventListener.java:70)
   at org.hibernate.impl.SessionImpl.fireSaveOrUpdate(SessionImpl.java:507)
   at org.hibernate.impl.SessionImpl.saveOrUpdate(SessionImpl.java:499)
   at org.hibernate.engine.CascadingAction$1.cascade(CascadingAction.java:218)
   at org.hibernate.engine.Cascade.cascadeToOne(Cascade.java:268)
   at org.hibernate.engine.Cascade.cascadeAssociation(Cascade.java:216)
   at org.hibernate.engine.Cascade.cascadeProperty(Cascade.java:169)
   at org.hibernate.engine.Cascade.cascade(Cascade.java:130)
   at org.hibernate.event.def.AbstractSaveEventListener.cascadeBeforeSave(AbstractSaveEventListener.java:412)
   at org.hibernate.event.def.AbstractSaveEventListener.performSaveOrReplicate(AbstractSaveEventListener.java:261)
   at org.hibernate.event.def.AbstractSaveEventListener.performSave(AbstractSaveEventListener.java:180)
   at org.hibernate.event.def.AbstractSaveEventListener.saveWithGeneratedId(AbstractSaveEventListener.java:108)
   at org.hibernate.event.def.DefaultSaveOrUpdateEventListener.saveWithGeneratedOrRequestedId(DefaultSaveOrUpdateEventListener.java:186)
   at org.hibernate.event.def.DefaultSaveOrUpdateEventListener.entityIsTransient(DefaultSaveOrUpdateEventListener.java:175)
   at org.hibernate.event.def.DefaultSaveOrUpdateEventListener.performSaveOrUpdate(DefaultSaveOrUpdateEventListener.java:98)
   at org.hibernate.event.def.DefaultSaveOrUpdateEventListener.onSaveOrUpdate(DefaultSaveOrUpdateEventListener.java:70)
   at org.hibernate.impl.SessionImpl.fireSaveOrUpdate(SessionImpl.java:507)
   at org.hibernate.impl.SessionImpl.saveOrUpdate(SessionImpl.java:499)
   at org.hibernate.engine.CascadingAction$1.cascade(CascadingAction.java:218)
   at org.hibernate.engine.Cascade.cascadeToOne(Cascade.java:268)
   at org.hibernate.engine.Cascade.cascadeAssociation(Cascade.java:216)
   at org.hibernate.engine.Cascade.cascadeProperty(Cascade.java:169)
   at org.hibernate.engine.Cascade.cascadeCollectionElements(Cascade.java:296)
   at org.hibernate.engine.Cascade.cascadeCollection(Cascade.java:242)
   at org.hibernate.engine.Cascade.cascadeAssociation(Cascade.java:219)
   at org.hibernate.engine.Cascade.cascadeProperty(Cascade.java:169)
   at org.hibernate.engine.Cascade.cascade(Cascade.java:130)
   at org.hibernate.event.def.AbstractSaveEventListener.cascadeAfterSave(AbstractSaveEventListener.java:437)
   at org.hibernate.event.def.AbstractSaveEventListener.performSaveOrReplicate(AbstractSaveEventListener.java:326)
   at org.hibernate.event.def.AbstractSaveEventListener.performSave(AbstractSaveEventListener.java:180)
   at org.hibernate.event.def.AbstractSaveEventListener.saveWithGeneratedId(AbstractSaveEventListener.java:108)
   at org.hibernate.event.def.DefaultSaveOrUpdateEventListener.saveWithGeneratedOrRequestedId(DefaultSaveOrUpdateEventListener.java:186)
   at org.hibernate.event.def.DefaultSaveOrUpdateEventListener.entityIsTransient(DefaultSaveOrUpdateEventListener.java:175)
   at org.hibernate.event.def.DefaultSaveOrUpdateEventListener.performSaveOrUpdate(DefaultSaveOrUpdateEventListener.java:98)
   at org.hibernate.event.def.DefaultSaveOrUpdateEventListener.onSaveOrUpdate(DefaultSaveOrUpdateEventListener.java:70)
   at org.hibernate.impl.SessionImpl.fireSaveOrUpdate(SessionImpl.java:507)
   at org.hibernate.impl.SessionImpl.saveOrUpdate(SessionImpl.java:499)
   at org.hibernate.impl.SessionImpl.saveOrUpdate(SessionImpl.java:495)
   at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
   at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
   at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
   at java.lang.reflect.Method.invoke(Method.java:585)
   at org.hibernate.context.ThreadLocalSessionContext$TransactionProtectionWrapper.invoke(ThreadLocalSessionContext.java:301)
   at $Proxy0.saveOrUpdate(Unknown Source)
   at hibtest.Main.doTransaction(Main.java:59)
   at hibtest.Main.run(Main.java:24)
   at hibtest.Main.main(Main.java:16)

Name and version of the database you are using: HSQLDB 1.8.0.4

The generated SQL (show_sql=true):

Code:

Hibernate: insert into ObjectRoot (object_root_id) values (null)
Hibernate: call identity()
Hibernate: insert into B (b_id) values (null)
Hibernate: call identity()
Hibernate: insert into A (a_id, name, b_id) values (null, ?, ?)
Hibernate: call identity()
Hibernate: insert into A (a_id, name, b_id) values (null, ?, ?)
Hibernate: call identity()

Top

abCOGhi1

Post subject: Re: Transient problem: Bidirectional cascade all-delete-orph

Posted: Mon Jan 08, 2007 6:29 pm

Newbie

Joined: Fri Jan 05, 2007 8:34 am
Posts: 3

Here's the debug log for this thread - it gets interesting around the 18:35:48,890 timecode.

It looks like the problem occurs cascading the from the ObjectRoot to the first A object to object B to the set of As held by B. The first A object is marked as persistent whilst cascading down this route, but not yet allocated an ID. The cascade from B back to the set of As generates IDs for the two other, as yet unsaved, As, but not for the first A as it had been marked as persistent.

The orphan deletion then occurs and this fails because the first A object doesn't yet have an ID allocated to it.

Any hints as to what I am doing wrong would be appreciated.

Code:

35:44,656  INFO Environment:500 - Hibernate 3.2.0
35:44,671  INFO Environment:533 - hibernate.properties not found
35:44,687  INFO Environment:667 - Bytecode provider name : cglib
35:44,687  INFO Environment:584 - using JDK 1.4 java.sql.Timestamp handling
35:44,843  INFO Configuration:1350 - configuring from resource: hibtest/hibernate.cfg.xml
35:44,843  INFO Configuration:1327 - Configuration resource: hibtest/hibernate.cfg.xml
35:45,390 DEBUG DTDEntityResolver:38 - trying to resolve system-id [http://hibernate.sourceforge.net/hibernate-configuration-3.0.dtd]
35:45,390 DEBUG DTDEntityResolver:40 - recognized hibernate namespace; attempting to resolve on classpath under org/hibernate/
35:45,406 DEBUG DTDEntityResolver:50 - located [http://hibernate.sourceforge.net/hibernate-configuration-3.0.dtd] in classpath
35:45,484 DEBUG Configuration:1311 - connection.driver_class=org.hsqldb.jdbcDriver
35:45,484 DEBUG Configuration:1311 - connection.url=jdbc:hsqldb:file:hibtestdb
35:45,484 DEBUG Configuration:1311 - connection.username=sa
35:45,484 DEBUG Configuration:1311 - connection.password=
35:45,484 DEBUG Configuration:1311 - connection.pool_size=1
35:45,484 DEBUG Configuration:1311 - dialect=org.hibernate.dialect.HSQLDialect
35:45,484 DEBUG Configuration:1311 - current_session_context_class=thread
35:45,484 DEBUG Configuration:1311 - cache.provider_class=org.hibernate.cache.NoCacheProvider
35:45,500 DEBUG Configuration:1311 - show_sql=false
35:45,500 DEBUG Configuration:1311 - hbm2ddl.auto=update
35:45,500 DEBUG Configuration:1510 - null<-org.dom4j.tree.DefaultAttribute@118fa47 [Attribute: name resource value "hibtest/ObjectRoot.hbm.xml"]
35:45,515  INFO Configuration:507 - Reading mappings from resource: hibtest/ObjectRoot.hbm.xml
35:45,515 DEBUG DTDEntityResolver:38 - trying to resolve system-id [http://hibernate.sourceforge.net/hibernate-mapping-3.0.dtd]
35:45,515 DEBUG DTDEntityResolver:40 - recognized hibernate namespace; attempting to resolve on classpath under org/hibernate/
35:45,515 DEBUG DTDEntityResolver:50 - located [http://hibernate.sourceforge.net/hibernate-mapping-3.0.dtd] in classpath
35:45,781  INFO HbmBinder:300 - Mapping class: hibtest.ObjectRoot -> ObjectRoot
35:45,828 DEBUG HbmBinder:1270 - Mapped property: id -> object_root_id
35:45,859 DEBUG HbmBinder:1270 - Mapped property: aList
35:45,859 DEBUG HbmBinder:1270 - Mapped property: bList
35:45,859 DEBUG Configuration:1510 - null<-org.dom4j.tree.DefaultAttribute@da90c [Attribute: name resource value "hibtest/A.hbm.xml"]
35:45,859  INFO Configuration:507 - Reading mappings from resource: hibtest/A.hbm.xml
35:45,875 DEBUG DTDEntityResolver:38 - trying to resolve system-id [http://hibernate.sourceforge.net/hibernate-mapping-3.0.dtd]
35:45,875 DEBUG DTDEntityResolver:40 - recognized hibernate namespace; attempting to resolve on classpath under org/hibernate/
35:45,875 DEBUG DTDEntityResolver:50 - located [http://hibernate.sourceforge.net/hibernate-mapping-3.0.dtd] in classpath
35:45,937  INFO HbmBinder:300 - Mapping class: hibtest.A -> A
35:45,937 DEBUG HbmBinder:1270 - Mapped property: id -> a_id
35:45,953 DEBUG HbmBinder:1270 - Mapped property: name -> name
35:46,140 DEBUG HbmBinder:1270 - Mapped property: b -> b_id
35:46,140 DEBUG Configuration:1510 - null<-org.dom4j.tree.DefaultAttribute@1d87b85 [Attribute: name resource value "hibtest/B.hbm.xml"]
35:46,140  INFO Configuration:507 - Reading mappings from resource: hibtest/B.hbm.xml
35:46,140 DEBUG DTDEntityResolver:38 - trying to resolve system-id [http://hibernate.sourceforge.net/hibernate-mapping-3.0.dtd]
35:46,140 DEBUG DTDEntityResolver:40 - recognized hibernate namespace; attempting to resolve on classpath under org/hibernate/
35:46,156 DEBUG DTDEntityResolver:50 - located [http://hibernate.sourceforge.net/hibernate-mapping-3.0.dtd] in classpath
35:46,218  INFO HbmBinder:300 - Mapping class: hibtest.B -> B
35:46,218 DEBUG HbmBinder:1270 - Mapped property: id -> b_id
35:46,218 DEBUG HbmBinder:1270 - Mapped property: aList
35:46,234  INFO Configuration:1465 - Configured SessionFactory: null
35:46,234 DEBUG Configuration:1466 - properties: {java.vendor=Sun Microsystems Inc., show_sql=false, hibernate.connection.url=jdbc:hsqldb:file:hibtestdb, sun.management.compiler=HotSpot Client Compiler, os.name=Windows XP, hbm2ddl.auto=update, sun.boot.class.path=C:\Java\jdk1.5.0_09\jre\lib\rt.jar;C:\Java\jdk1.5.0_09\jre\lib\i18n.jar;C:\Java\jdk1.5.0_09\jre\lib\sunrsasign.jar;C:\Java\jdk1.5.0_09\jre\lib\jsse.jar;C:\Java\jdk1.5.0_09\jre\lib\jce.jar;C:\Java\jdk1.5.0_09\jre\lib\charsets.jar;C:\Java\jdk1.5.0_09\jre\classes, hibernate.current_session_context_class=thread, sun.desktop=windows, java.vm.specification.vendor=Sun Microsystems Inc., java.runtime.version=1.5.0_09-b03, hibernate.cache.provider_class=org.hibernate.cache.NoCacheProvider, user.name=chris_2, connection.driver_class=org.hsqldb.jdbcDriver, current_session_context_class=thread, user.language=en, sun.boot.library.path=C:\Java\jdk1.5.0_09\jre\bin, dialect=org.hibernate.dialect.HSQLDialect, java.version=1.5.0_09, user.timezone=Europe/London, sun.arch.data.model=32, java.endorsed.dirs=C:\Java\jdk1.5.0_09\jre\lib\endorsed, sun.cpu.isalist=pentium_pro+mmx pentium_pro pentium+mmx pentium i486 i386 i86, sun.jnu.encoding=Cp1252, file.encoding.pkg=sun.io, file.separator=\, java.specification.name=Java Platform API Specification, java.class.version=49.0, user.country=GB, connection.url=jdbc:hsqldb:file:hibtestdb, java.home=C:\Java\jdk1.5.0_09\jre, java.vm.info=mixed mode, os.version=5.1, path.separator=;, connection.password=, java.vm.version=1.5.0_09-b03, hibernate.connection.password=, user.variant=, java.awt.printerjob=sun.awt.windows.WPrinterJob, sun.io.unicode.encoding=UnicodeLittle, awt.toolkit=sun.awt.windows.WToolkit, hibernate.connection.username=sa, user.home=C:\Documents and Settings\chris_2, java.specification.vendor=Sun Microsystems Inc., hibernate.hbm2ddl.auto=update, java.library.path=C:\Java\jdk1.5.0_09\bin;.;C:\WINDOWS\system32;C:\WINDOWS;C:\WINDOWS\system32;C:\WINDOWS;C:\WINDOWS\System32\Wbem;C:\Program Files\Subversion\bin;C:\Java\jdk1.5.0_09\bin;C:\cygwin\bin, java.vendor.url=http://java.sun.com/, hibernate.connection.driver_class=org.hsqldb.jdbcDriver, connection.username=sa, java.vm.vendor=Sun Microsystems Inc., hibernate.dialect=org.hibernate.dialect.HSQLDialect, java.runtime.name=Java(TM) 2 Runtime Environment, Standard Edition, java.class.path=C:\Java\jdk1.5.0_09\jre\lib\charsets.jar;C:\Java\jdk1.5.0_09\jre\lib\deploy.jar;C:\Java\jdk1.5.0_09\jre\lib\javaws.jar;C:\Java\jdk1.5.0_09\jre\lib\jce.jar;C:\Java\jdk1.5.0_09\jre\lib\jsse.jar;C:\Java\jdk1.5.0_09\jre\lib\plugin.jar;C:\Java\jdk1.5.0_09\jre\lib\rt.jar;C:\Java\jdk1.5.0_09\jre\lib\ext\dnsns.jar;C:\Java\jdk1.5.0_09\jre\lib\ext\localedata.jar;C:\Java\jdk1.5.0_09\jre\lib\ext\sunjce_provider.jar;C:\Java\jdk1.5.0_09\jre\lib\ext\sunpkcs11.jar;C:\development\hibtest\classes\test\hibtest;C:\development\hibtest\classes\production\hibtest;C:\Java\lib\hibernate-3.2\hibernate3.jar;C:\Java\lib\hibernate-3.2\lib\jboss-system.jar;C:\Java\lib\hibernate-3.2\lib\ant-junit-1.6.5.jar;C:\Java\lib\hibernate-3.2\lib\dom4j-1.6.1.jar;C:\Java\lib\hibernate-3.2\lib\concurrent-1.3.2.jar;C:\Java\lib\hibernate-3.2\lib\commons-collections-2.1.1.jar;C:\Java\lib\hibernate-3.2\lib\ant-1.6.5.jar;C:\Java\lib\hibernate-3.2\lib\syndiag2.jar;C:\Java\lib\hibernate-3.2\lib\jaas.jar;C:\Java\lib\hibernate-3.2\lib\ehcache-1.2.jar;C:\Java\lib\hibernate-3.2\lib\junit-3.8.1.jar;C:\Java\lib\hibernate-3.2\lib\xml-apis.jar;C:\Java\lib\hibernate-3.2\lib\cleanimports.jar;C:\Java\lib\hibernate-3.2\lib\cglib-2.1.3.jar;C:\Java\lib\hibernate-3.2\lib\checkstyle-all.jar;C:\Java\lib\hibernate-3.2\lib\ant-launcher-1.6.5.jar;C:\Java\lib\hibernate-3.2\lib\jboss-cache.jar;C:\Java\lib\hibernate-3.2\lib\log4j-1.2.11.jar;C:\Java\lib\hibernate-3.2\lib\jboss-jmx.jar;C:\Java\lib\hibernate-3.2\lib\jacc-1_0-fr.jar;C:\Java\lib\hibernate-3.2\lib\proxool-0.8.3.jar;C:\Java\lib\hibernate-3.2\lib\antlr-2.7.6.jar;C:\Java\lib\hibernate-3.2\lib\ant-antlr-1.6.5.jar;C:\Java\lib\hibernate-3.2\lib\versioncheck.jar;C:\Java\lib\hibernate-3.2\lib\asm.jar;C:\Java\lib\hibernate-3.2\lib\asm-attrs.jar;C:\Java\lib\hibernate-3.2\lib\swarmcache-1.0rc2.jar;C:\Java\lib\hibernate-3.2\lib\jgroups-2.2.8.jar;C:\Java\lib\hibernate-3.2\lib\ant-swing-1.6.5.jar;C:\Java\lib\hibernate-3.2\lib\javassist.jar;C:\Java\lib\hibernate-3.2\lib\oscache-2.1.jar;C:\Java\lib\hibernate-3.2\lib\jdbc2_0-stdext.jar;C:\Java\lib\hibernate-3.2\lib\jta.jar;C:\Java\lib\hibernate-3.2\lib\jaxen-1.1-beta-7.jar;C:\Java\lib\hibernate-3.2\lib\c3p0-0.9.0.jar;C:\Java\lib\hibernate-3.2\lib\connector.jar;C:\Java\lib\hibernate-3.2\lib\xerces-2.6.2.jar;C:\Java\lib\hibernate-3.2\lib\jboss-common.jar;C:\Java\lib\hibernate-3.2\lib\commons-logging-1.0.4.jar;C:\Java\lib\hsqldb\hsqldb-1.8.0.7\lib\hsqldb.jar;C:\Program Files\JetBrains\IntelliJ IDEA 6.0\lib\idea_rt.jar, hibernate.bytecode.use_reflection_optimizer=false, java.vm.specification.name=Java Virtual Machine Specification, java.vm.specification.version=1.0, sun.cpu.endian=little, sun.os.patch.level=Service Pack 2, connection.pool_size=1, java.io.tmpdir=C:\DOCUME~1\chris_2\LOCALS~1\Temp\, java.vendor.url.bug=http://java.sun.com/cgi-bin/bugreport.cgi, os.arch=x86, java.awt.graphicsenv=sun.awt.Win32GraphicsEnvironment, java.ext.dirs=C:\Java\jdk1.5.0_09\jre\lib\ext, user.dir=C:\development\hibtest, line.separator=
, java.vm.name=Java HotSpot(TM) Client VM, cache.provider_class=org.hibernate.cache.NoCacheProvider, file.encoding=windows-1252, java.specification.version=1.5, hibernate.show_sql=false, hibernate.connection.pool_size=1}
35:46,234 DEBUG Configuration:1209 - Preparing to build session factory with filters : {}
35:46,234 DEBUG Configuration:1044 - processing extends queue
35:46,234 DEBUG Configuration:1048 - processing collection mappings
35:46,234 DEBUG CollectionSecondPass:41 - Second pass for collection: hibtest.ObjectRoot.aList
35:46,234  INFO HbmBinder:2375 - Mapping collection: hibtest.ObjectRoot.aList -> A
35:46,234 DEBUG CollectionSecondPass:57 - Mapped collection key: object_root_id, index: a_index, one-to-many: hibtest.A
35:46,234 DEBUG CollectionSecondPass:41 - Second pass for collection: hibtest.ObjectRoot.bList
35:46,234  INFO HbmBinder:2375 - Mapping collection: hibtest.ObjectRoot.bList -> B
35:46,234 DEBUG CollectionSecondPass:57 - Mapped collection key: object_root_id, index: b_index, one-to-many: hibtest.B
35:46,234 DEBUG CollectionSecondPass:41 - Second pass for collection: hibtest.B.aList
35:46,250  INFO HbmBinder:2375 - Mapping collection: hibtest.B.aList -> A
35:46,250 DEBUG CollectionSecondPass:57 - Mapped collection key: b_id, one-to-many: hibtest.A
35:46,250 DEBUG Configuration:1059 - processing native query and ResultSetMapping mappings
35:46,250 DEBUG Configuration:1067 - processing association property references
35:46,250 DEBUG Configuration:1089 - processing foreign key constraints
35:46,250 DEBUG Configuration:1172 - resolving reference to class: hibtest.ObjectRoot
35:46,250 DEBUG Configuration:1172 - resolving reference to class: hibtest.B
35:46,250 DEBUG Configuration:1172 - resolving reference to class: hibtest.ObjectRoot
35:46,281  INFO DriverManagerConnectionProvider:41 - Using Hibernate built-in connection pool (not for production use!)
35:46,281  INFO DriverManagerConnectionProvider:42 - Hibernate connection pool size: 1
35:46,281  INFO DriverManagerConnectionProvider:45 - autocommit mode: false
35:46,296  INFO DriverManagerConnectionProvider:80 - using driver: org.hsqldb.jdbcDriver at URL: jdbc:hsqldb:file:hibtestdb
35:46,296  INFO DriverManagerConnectionProvider:83 - connection properties: {user=sa, password=}
35:46,296 DEBUG DriverManagerConnectionProvider:93 - total checked-out connections: 0
35:46,296 DEBUG DriverManagerConnectionProvider:109 - opening new JDBC connection
35:47,093 DEBUG DriverManagerConnectionProvider:115 - created connection to: jdbc:hsqldb:file:hibtestdb, Isolation Level: 2
35:47,140  INFO SettingsFactory:81 - RDBMS: HSQL Database Engine, version: 1.8.0
35:47,140  INFO SettingsFactory:82 - JDBC driver: HSQL Database Engine Driver, version: 1.8.0
35:47,140 DEBUG DriverManagerConnectionProvider:129 - returning connection to pool, pool size: 1
35:47,218  INFO Dialect:141 - Using dialect: org.hibernate.dialect.HSQLDialect
35:47,234  INFO TransactionFactoryFactory:31 - Using default transaction strategy (direct JDBC transactions)
35:47,250  INFO TransactionManagerLookupFactory:33 - No TransactionManagerLookup configured (in JTA environment, use of read-write or transactional second-level cache is not recommended)
35:47,250  INFO SettingsFactory:134 - Automatic flush during beforeCompletion(): disabled
35:47,250  INFO SettingsFactory:138 - Automatic session close at end of transaction: disabled
35:47,250  INFO SettingsFactory:145 - JDBC batch size: 15
35:47,250  INFO SettingsFactory:148 - JDBC batch updates for versioned data: disabled
35:47,250  INFO SettingsFactory:153 - Scrollable result sets: enabled
35:47,250 DEBUG SettingsFactory:157 - Wrap result sets: disabled
35:47,250  INFO SettingsFactory:161 - JDBC3 getGeneratedKeys(): disabled
35:47,250  INFO SettingsFactory:169 - Connection release mode: auto
35:47,250  INFO SettingsFactory:196 - Default batch fetch size: 1
35:47,265  INFO SettingsFactory:200 - Generate SQL with comments: disabled
35:47,265  INFO SettingsFactory:204 - Order SQL updates by primary key: disabled
35:47,265  INFO SettingsFactory:369 - Query translator: org.hibernate.hql.ast.ASTQueryTranslatorFactory
35:47,265  INFO ASTQueryTranslatorFactory:24 - Using ASTQueryTranslatorFactory
35:47,265  INFO SettingsFactory:212 - Query language substitutions: {}
35:47,265  INFO SettingsFactory:217 - JPA-QL strict compliance: disabled
35:47,265  INFO SettingsFactory:222 - Second-level cache: enabled
35:47,265  INFO SettingsFactory:226 - Query cache: disabled
35:47,265  INFO SettingsFactory:356 - Cache provider: org.hibernate.cache.NoCacheProvider
35:47,265  INFO SettingsFactory:241 - Optimize cache for minimal puts: disabled
35:47,265  INFO SettingsFactory:250 - Structured second-level cache entries: disabled
35:47,281 DEBUG SQLExceptionConverterFactory:52 - Using dialect defined converter
35:47,281  INFO SettingsFactory:277 - Statistics: disabled
35:47,281  INFO SettingsFactory:281 - Deleted entity synthetic identifier rollback: disabled
35:47,281  INFO SettingsFactory:296 - Default entity-mode: pojo
35:47,406  INFO SessionFactoryImpl:161 - building session factory
35:47,406 DEBUG SessionFactoryImpl:173 - Session factory constructed with filter configurations : {}
35:47,406 DEBUG SessionFactoryImpl:177 - instantiating session factory with properties: {java.vendor=Sun Microsystems Inc., show_sql=false, hibernate.connection.url=jdbc:hsqldb:file:hibtestdb, sun.management.compiler=HotSpot Client Compiler, os.name=Windows XP, hbm2ddl.auto=update, sun.boot.class.path=C:\Java\jdk1.5.0_09\jre\lib\rt.jar;C:\Java\jdk1.5.0_09\jre\lib\i18n.jar;C:\Java\jdk1.5.0_09\jre\lib\sunrsasign.jar;C:\Java\jdk1.5.0_09\jre\lib\jsse.jar;C:\Java\jdk1.5.0_09\jre\lib\jce.jar;C:\Java\jdk1.5.0_09\jre\lib\charsets.jar;C:\Java\jdk1.5.0_09\jre\classes, hibernate.current_session_context_class=thread, sun.desktop=windows, java.vm.specification.vendor=Sun Microsystems Inc., java.runtime.version=1.5.0_09-b03, hibernate.cache.provider_class=org.hibernate.cache.NoCacheProvider, user.name=chris_2, connection.driver_class=org.hsqldb.jdbcDriver, current_session_context_class=thread, user.language=en, sun.boot.library.path=C:\Java\jdk1.5.0_09\jre\bin, dialect=org.hibernate.dialect.HSQLDialect, java.version=1.5.0_09, user.timezone=Europe/London, sun.arch.data.model=32, java.endorsed.dirs=C:\Java\jdk1.5.0_09\jre\lib\endorsed, sun.cpu.isalist=pentium_pro+mmx pentium_pro pentium+mmx pentium i486 i386 i86, sun.jnu.encoding=Cp1252, file.encoding.pkg=sun.io, file.separator=\, java.specification.name=Java Platform API Specification, java.class.version=49.0, user.country=GB, connection.url=jdbc:hsqldb:file:hibtestdb, java.home=C:\Java\jdk1.5.0_09\jre, java.vm.info=mixed mode, os.version=5.1, path.separator=;, connection.password=, java.vm.version=1.5.0_09-b03, hibernate.connection.password=, user.variant=, java.awt.printerjob=sun.awt.windows.WPrinterJob, sun.io.unicode.encoding=UnicodeLittle, awt.toolkit=sun.awt.windows.WToolkit, hibernate.connection.username=sa, user.home=C:\Documents and Settings\chris_2, java.specification.vendor=Sun Microsystems Inc., hibernate.hbm2ddl.auto=update, java.library.path=C:\Java\jdk1.5.0_09\bin;.;C:\WINDOWS\system32;C:\WINDOWS;C:\WINDOWS\system32;C:\WINDOWS;C:\WINDOWS\System32\Wbem;C:\Program Files\Subversion\bin;C:\Java\jdk1.5.0_09\bin;C:\cygwin\bin, java.vendor.url=http://java.sun.com/, hibernate.connection.driver_class=org.hsqldb.jdbcDriver, connection.username=sa, java.vm.vendor=Sun Microsystems Inc., hibernate.dialect=org.hibernate.dialect.HSQLDialect, java.runtime.name=Java(TM) 2 Runtime Environment, Standard Edition, java.class.path=C:\Java\jdk1.5.0_09\jre\lib\charsets.jar;C:\Java\jdk1.5.0_09\jre\lib\deploy.jar;C:\Java\jdk1.5.0_09\jre\lib\javaws.jar;C:\Java\jdk1.5.0_09\jre\lib\jce.jar;C:\Java\jdk1.5.0_09\jre\lib\jsse.jar;C:\Java\jdk1.5.0_09\jre\lib\plugin.jar;C:\Java\jdk1.5.0_09\jre\lib\rt.jar;C:\Java\jdk1.5.0_09\jre\lib\ext\dnsns.jar;C:\Java\jdk1.5.0_09\jre\lib\ext\localedata.jar;C:\Java\jdk1.5.0_09\jre\lib\ext\sunjce_provider.jar;C:\Java\jdk1.5.0_09\jre\lib\ext\sunpkcs11.jar;C:\development\hibtest\classes\test\hibtest;C:\development\hibtest\classes\production\hibtest;C:\Java\lib\hibernate-3.2\hibernate3.jar;C:\Java\lib\hibernate-3.2\lib\jboss-system.jar;C:\Java\lib\hibernate-3.2\lib\ant-junit-1.6.5.jar;C:\Java\lib\hibernate-3.2\lib\dom4j-1.6.1.jar;C:\Java\lib\hibernate-3.2\lib\concurrent-1.3.2.jar;C:\Java\lib\hibernate-3.2\lib\commons-collections-2.1.1.jar;C:\Java\lib\hibernate-3.2\lib\ant-1.6.5.jar;C:\Java\lib\hibernate-3.2\lib\syndiag2.jar;C:\Java\lib\hibernate-3.2\lib\jaas.jar;C:\Java\lib\hibernate-3.2\lib\ehcache-1.2.jar;C:\Java\lib\hibernate-3.2\lib\junit-3.8.1.jar;C:\Java\lib\hibernate-3.2\lib\xml-apis.jar;C:\Java\lib\hibernate-3.2\lib\cleanimports.jar;C:\Java\lib\hibernate-3.2\lib\cglib-2.1.3.jar;C:\Java\lib\hibernate-3.2\lib\checkstyle-all.jar;C:\Java\lib\hibernate-3.2\lib\ant-launcher-1.6.5.jar;C:\Java\lib\hibernate-3.2\lib\jboss-cache.jar;C:\Java\lib\hibernate-3.2\lib\log4j-1.2.11.jar;C:\Java\lib\hibernate-3.2\lib\jboss-jmx.jar;C:\Java\lib\hibernate-3.2\lib\jacc-1_0-fr.jar;C:\Java\lib\hibernate-3.2\lib\proxool-0.8.3.jar;C:\Java\lib\hibernate-3.2\lib\antlr-2.7.6.jar;C:\Java\lib\hibernate-3.2\lib\ant-antlr-1.6.5.jar;C:\Java\lib\hibernate-3.2\lib\versioncheck.jar;C:\Java\lib\hibernate-3.2\lib\asm.jar;C:\Java\lib\hibernate-3.2\lib\asm-attrs.jar;C:\Java\lib\hibernate-3.2\lib\swarmcache-1.0rc2.jar;C:\Java\lib\hibernate-3.2\lib\jgroups-2.2.8.jar;C:\Java\lib\hibernate-3.2\lib\ant-swing-1.6.5.jar;C:\Java\lib\hibernate-3.2\lib\javassist.jar;C:\Java\lib\hibernate-3.2\lib\oscache-2.1.jar;C:\Java\lib\hibernate-3.2\lib\jdbc2_0-stdext.jar;C:\Java\lib\hibernate-3.2\lib\jta.jar;C:\Java\lib\hibernate-3.2\lib\jaxen-1.1-beta-7.jar;C:\Java\lib\hibernate-3.2\lib\c3p0-0.9.0.jar;C:\Java\lib\hibernate-3.2\lib\connector.jar;C:\Java\lib\hibernate-3.2\lib\xerces-2.6.2.jar;C:\Java\lib\hibernate-3.2\lib\jboss-common.jar;C:\Java\lib\hibernate-3.2\lib\commons-logging-1.0.4.jar;C:\Java\lib\hsqldb\hsqldb-1.8.0.7\lib\hsqldb.jar;C:\Program Files\JetBrains\IntelliJ IDEA 6.0\lib\idea_rt.jar, hibernate.bytecode.use_reflection_optimizer=false, java.vm.specification.name=Java Virtual Machine Specification, java.vm.specification.version=1.0, sun.cpu.endian=little, sun.os.patch.level=Service Pack 2, connection.pool_size=1, java.io.tmpdir=C:\DOCUME~1\chris_2\LOCALS~1\Temp\, java.vendor.url.bug=http://java.sun.com/cgi-bin/bugreport.cgi, os.arch=x86, java.awt.graphicsenv=sun.awt.Win32GraphicsEnvironment, java.ext.dirs=C:\Java\jdk1.5.0_09\jre\lib\ext, user.dir=C:\development\hibtest, line.separator=
, java.vm.name=Java HotSpot(TM) Client VM, cache.provider_class=org.hibernate.cache.NoCacheProvider, file.encoding=windows-1252, java.specification.version=1.5, hibernate.connection.pool_size=1, hibernate.show_sql=false}
35:48,062 DEBUG AbstractEntityPersister:2673 - Static SQL for entity: hibtest.B
35:48,062 DEBUG AbstractEntityPersister:2678 -  Version select: select b_id from B where b_id =?
35:48,062 DEBUG AbstractEntityPersister:2681 -  Snapshot select: select b_.b_id from B b_ where b_.b_id=?
35:48,062 DEBUG AbstractEntityPersister:2684 -  Insert 0: insert into B (b_id) values (?)
35:48,062 DEBUG AbstractEntityPersister:2685 -  Update 0: null
35:48,062 DEBUG AbstractEntityPersister:2686 -  Delete 0: delete from B where b_id=?
35:48,062 DEBUG AbstractEntityPersister:2690 -  Identity insert: insert into B (b_id) values (null)
35:48,078 DEBUG AbstractEntityPersister:2673 - Static SQL for entity: hibtest.A
35:48,078 DEBUG AbstractEntityPersister:2678 -  Version select: select a_id from A where a_id =?
35:48,078 DEBUG AbstractEntityPersister:2681 -  Snapshot select: select a_.a_id, a_.name as name1_, a_.b_id as b3_1_ from A a_ where a_.a_id=?
35:48,078 DEBUG AbstractEntityPersister:2684 -  Insert 0: insert into A (name, b_id, a_id) values (?, ?, ?)
35:48,078 DEBUG AbstractEntityPersister:2685 -  Update 0: update A set name=?, b_id=? where a_id=?
35:48,078 DEBUG AbstractEntityPersister:2686 -  Delete 0: delete from A where a_id=?
35:48,078 DEBUG AbstractEntityPersister:2690 -  Identity insert: insert into A (a_id, name, b_id) values (null, ?, ?)
35:48,109 DEBUG AbstractEntityPersister:2673 - Static SQL for entity: hibtest.ObjectRoot
35:48,109 DEBUG AbstractEntityPersister:2678 -  Version select: select object_root_id from ObjectRoot where object_root_id =?
35:48,109 DEBUG AbstractEntityPersister:2681 -  Snapshot select: select objectroot_.object_root_id from ObjectRoot objectroot_ where objectroot_.object_root_id=?
35:48,109 DEBUG AbstractEntityPersister:2684 -  Insert 0: insert into ObjectRoot (object_root_id) values (?)
35:48,109 DEBUG AbstractEntityPersister:2685 -  Update 0: null
35:48,109 DEBUG AbstractEntityPersister:2686 -  Delete 0: delete from ObjectRoot where object_root_id=?
35:48,109 DEBUG AbstractEntityPersister:2690 -  Identity insert: insert into ObjectRoot (object_root_id) values (null)
35:48,125 DEBUG AbstractCollectionPersister:548 - Static SQL for collection: hibtest.ObjectRoot.aList
35:48,140 DEBUG AbstractCollectionPersister:550 -  Row insert: update A set object_root_id=?, a_index=? where a_id=?
35:48,140 DEBUG AbstractCollectionPersister:556 -  Row delete: update A set object_root_id=null, a_index=null where object_root_id=? and a_id=?
35:48,140 DEBUG AbstractCollectionPersister:559 -  One-shot delete: update A set object_root_id=null, a_index=null where object_root_id=?
35:48,140 DEBUG AbstractCollectionPersister:548 - Static SQL for collection: hibtest.ObjectRoot.bList
35:48,140 DEBUG AbstractCollectionPersister:550 -  Row insert: update B set object_root_id=?, b_index=? where b_id=?
35:48,140 DEBUG AbstractCollectionPersister:556 -  Row delete: update B set object_root_id=null, b_index=null where object_root_id=? and b_id=?
35:48,140 DEBUG AbstractCollectionPersister:559 -  One-shot delete: update B set object_root_id=null, b_index=null where object_root_id=?
35:48,140 DEBUG AbstractCollectionPersister:548 - Static SQL for collection: hibtest.B.aList
35:48,140 DEBUG AbstractCollectionPersister:550 -  Row insert: update A set b_id=? where a_id=?
35:48,140 DEBUG AbstractCollectionPersister:556 -  Row delete: update A set b_id=null where b_id=? and a_id=?
35:48,140 DEBUG AbstractCollectionPersister:559 -  One-shot delete: update A set b_id=null where b_id=?
35:48,203 DEBUG EntityLoader:79 - Static select for entity hibtest.A: select a0_.a_id as a1_1_0_, a0_.name as name1_0_, a0_.b_id as b3_1_0_ from A a0_ where a0_.a_id=?
35:48,203 DEBUG EntityLoader:79 - Static select for entity hibtest.A: select a0_.a_id as a1_1_0_, a0_.name as name1_0_, a0_.b_id as b3_1_0_ from A a0_ where a0_.a_id=?
35:48,203 DEBUG EntityLoader:79 - Static select for entity hibtest.A: select a0_.a_id as a1_1_0_, a0_.name as name1_0_, a0_.b_id as b3_1_0_ from A a0_ where a0_.a_id=?
35:48,218 DEBUG EntityLoader:79 - Static select for entity hibtest.A: select a0_.a_id as a1_1_0_, a0_.name as name1_0_, a0_.b_id as b3_1_0_ from A a0_ where a0_.a_id=?
35:48,218 DEBUG EntityLoader:79 - Static select for entity hibtest.A: select a0_.a_id as a1_1_0_, a0_.name as name1_0_, a0_.b_id as b3_1_0_ from A a0_ where a0_.a_id=?
35:48,250 DEBUG EntityLoader:34 - Static select for action ACTION_MERGE on entity hibtest.A: select a0_.a_id as a1_1_1_, a0_.name as name1_1_, a0_.b_id as b3_1_1_, b1_.b_id as b1_2_0_ from A a0_ left outer join B b1_ on a0_.b_id=b1_.b_id where a0_.a_id=?
35:48,250 DEBUG EntityLoader:34 - Static select for action ACTION_REFRESH on entity hibtest.A: select a0_.a_id as a1_1_1_, a0_.name as name1_1_, a0_.b_id as b3_1_1_, b1_.b_id as b1_2_0_ from A a0_ left outer join B b1_ on a0_.b_id=b1_.b_id where a0_.a_id=?
35:48,250 DEBUG EntityLoader:79 - Static select for entity hibtest.B: select b0_.b_id as b1_2_0_ from B b0_ where b0_.b_id=?
35:48,250 DEBUG EntityLoader:79 - Static select for entity hibtest.B: select b0_.b_id as b1_2_0_ from B b0_ where b0_.b_id=?
35:48,250 DEBUG EntityLoader:79 - Static select for entity hibtest.B: select b0_.b_id as b1_2_0_ from B b0_ where b0_.b_id=?
35:48,250 DEBUG EntityLoader:79 - Static select for entity hibtest.B: select b0_.b_id as b1_2_0_ from B b0_ where b0_.b_id=?
35:48,250 DEBUG EntityLoader:79 - Static select for entity hibtest.B: select b0_.b_id as b1_2_0_ from B b0_ where b0_.b_id=?
35:48,265 DEBUG EntityLoader:34 - Static select for action ACTION_MERGE on entity hibtest.B: select b0_.b_id as b1_2_1_, alist1_.b_id as b3_3_, alist1_.a_id as a1_3_, alist1_.a_id as a1_1_0_, alist1_.name as name1_0_, alist1_.b_id as b3_1_0_ from B b0_ left outer join A alist1_ on b0_.b_id=alist1_.b_id where b0_.b_id=?
35:48,265 DEBUG EntityLoader:34 - Static select for action ACTION_REFRESH on entity hibtest.B: select b0_.b_id as b1_2_1_, alist1_.b_id as b3_3_, alist1_.a_id as a1_3_, alist1_.a_id as a1_1_0_, alist1_.name as name1_0_, alist1_.b_id as b3_1_0_ from B b0_ left outer join A alist1_ on b0_.b_id=alist1_.b_id where b0_.b_id=?
35:48,265 DEBUG EntityLoader:79 - Static select for entity hibtest.ObjectRoot: select objectroot0_.object_root_id as object1_0_0_ from ObjectRoot objectroot0_ where objectroot0_.object_root_id=?
35:48,265 DEBUG EntityLoader:79 - Static select for entity hibtest.ObjectRoot: select objectroot0_.object_root_id as object1_0_0_ from ObjectRoot objectroot0_ where objectroot0_.object_root_id=?
35:48,265 DEBUG EntityLoader:79 - Static select for entity hibtest.ObjectRoot: select objectroot0_.object_root_id as object1_0_0_ from ObjectRoot objectroot0_ where objectroot0_.object_root_id=?
35:48,265 DEBUG EntityLoader:79 - Static select for entity hibtest.ObjectRoot: select objectroot0_.object_root_id as object1_0_0_ from ObjectRoot objectroot0_ where objectroot0_.object_root_id=?
35:48,265 DEBUG EntityLoader:79 - Static select for entity hibtest.ObjectRoot: select objectroot0_.object_root_id as object1_0_0_ from ObjectRoot objectroot0_ where objectroot0_.object_root_id=?
35:48,281 DEBUG EntityLoader:34 - Static select for action ACTION_MERGE on entity hibtest.ObjectRoot: select objectroot0_.object_root_id as object1_0_2_, alist1_.object_root_id as object4_4_, alist1_.a_id as a1_4_, alist1_.a_index as a5_4_, alist1_.a_id as a1_1_0_, alist1_.name as name1_0_, alist1_.b_id as b3_1_0_, b2_.b_id as b1_2_1_ from ObjectRoot objectroot0_ left outer join A alist1_ on objectroot0_.object_root_id=alist1_.object_root_id left outer join B b2_ on alist1_.b_id=b2_.b_id where objectroot0_.object_root_id=?
35:48,281 DEBUG EntityLoader:34 - Static select for action ACTION_REFRESH on entity hibtest.ObjectRoot: select objectroot0_.object_root_id as object1_0_2_, alist1_.object_root_id as object4_4_, alist1_.a_id as a1_4_, alist1_.a_index as a5_4_, alist1_.a_id as a1_1_0_, alist1_.name as name1_0_, alist1_.b_id as b3_1_0_, b2_.b_id as b1_2_1_ from ObjectRoot objectroot0_ left outer join A alist1_ on objectroot0_.object_root_id=alist1_.object_root_id left outer join B b2_ on alist1_.b_id=b2_.b_id where objectroot0_.object_root_id=?
35:48,328 DEBUG OneToManyLoader:64 - Static select for one-to-many hibtest.ObjectRoot.aList: select alist0_.object_root_id as object4_1_, alist0_.a_id as a1_1_, alist0_.a_index as a5_1_, alist0_.a_id as a1_1_0_, alist0_.name as name1_0_, alist0_.b_id as b3_1_0_ from A alist0_ where alist0_.object_root_id=?
35:48,328 DEBUG OneToManyLoader:64 - Static select for one-to-many hibtest.ObjectRoot.bList: select blist0_.object_root_id as object2_1_, blist0_.b_id as b1_1_, blist0_.b_index as b3_1_, blist0_.b_id as b1_2_0_ from B blist0_ where blist0_.object_root_id=?
35:48,328 DEBUG OneToManyLoader:64 - Static select for one-to-many hibtest.B.aList: select alist0_.b_id as b3_1_, alist0_.a_id as a1_1_, alist0_.a_id as a1_1_0_, alist0_.name as name1_0_, alist0_.b_id as b3_1_0_ from A alist0_ where alist0_.b_id=?
35:48,328 DEBUG SessionFactoryObjectFactory:39 - initializing class SessionFactoryObjectFactory
35:48,359 DEBUG SessionFactoryObjectFactory:76 - registered: 402819811002fea5011002fea8e80000 (unnamed)
35:48,359  INFO SessionFactoryObjectFactory:82 - Not binding factory to JNDI, no JNDI name configured
35:48,359 DEBUG SessionFactoryImpl:308 - instantiated session factory
35:48,359  INFO SchemaUpdate:115 - Running hbm2ddl schema update
35:48,359  INFO SchemaUpdate:126 - fetching database metadata
35:48,359 DEBUG DriverManagerConnectionProvider:93 - total checked-out connections: 0
35:48,359 DEBUG DriverManagerConnectionProvider:99 - using pooled JDBC connection, pool size: 0
35:48,375  INFO SchemaUpdate:138 - updating schema
35:48,375 DEBUG Configuration:1044 - processing extends queue
35:48,375 DEBUG Configuration:1048 - processing collection mappings
35:48,375 DEBUG Configuration:1059 - processing native query and ResultSetMapping mappings
35:48,375 DEBUG Configuration:1067 - processing association property references
35:48,375 DEBUG Configuration:1089 - processing foreign key constraints
35:48,375 DEBUG Configuration:1172 - resolving reference to class: hibtest.ObjectRoot
35:48,375 DEBUG Configuration:1172 - resolving reference to class: hibtest.B
35:48,375 DEBUG Configuration:1172 - resolving reference to class: hibtest.ObjectRoot
35:48,531  INFO TableMetadata:40 - table found: PUBLIC.A
35:48,531  INFO TableMetadata:41 - columns: [object_root_id, b_id, name, a_index, a_id]
35:48,531  INFO TableMetadata:43 - foreign keys: [fk41e3309abf, fk41e8e58ab4]
35:48,531  INFO TableMetadata:44 - indexes: [sys_idx_46, sys_idx_52, sys_idx_54]
35:48,562  INFO TableMetadata:40 - table found: PUBLIC.B
35:48,562  INFO TableMetadata:41 - columns: [object_root_id, b_id, b_index]
35:48,562  INFO TableMetadata:43 - foreign keys: [fk42e8e58ab4]
35:48,562  INFO TableMetadata:44 - indexes: [sys_idx_48, sys_idx_56]
35:48,562  INFO TableMetadata:40 - table found: PUBLIC.OBJECTROOT
35:48,562  INFO TableMetadata:41 - columns: [object_root_id]
35:48,562  INFO TableMetadata:43 - foreign keys: []
35:48,562  INFO TableMetadata:44 - indexes: [sys_idx_50]
35:48,562  INFO SchemaUpdate:160 - schema update complete
35:48,593 DEBUG DriverManagerConnectionProvider:129 - returning connection to pool, pool size: 1
35:48,625 DEBUG SessionFactoryImpl:390 - Checking 0 named HQL queries
35:48,625 DEBUG SessionFactoryImpl:410 - Checking 0 named SQL queries
35:48,703 DEBUG SessionImpl:220 - opened session at timestamp: 11682813486
35:48,890 DEBUG ThreadLocalSessionContext:290 - allowing method [beginTransaction] in non-transacted context
35:48,890 DEBUG ThreadLocalSessionContext:300 - allowing proxied method [beginTransaction] to proceed to real session
35:48,890 DEBUG JDBCTransaction:54 - begin
35:48,890 DEBUG ConnectionManager:415 - opening JDBC connection
35:48,890 DEBUG DriverManagerConnectionProvider:93 - total checked-out connections: 0
35:48,890 DEBUG DriverManagerConnectionProvider:99 - using pooled JDBC connection, pool size: 0
35:48,890 DEBUG JDBCTransaction:59 - current autocommit status: false
35:48,890 DEBUG JDBCContext:210 - after transaction begin
35:48,890 DEBUG ThreadLocalSessionContext:300 - allowing proxied method [saveOrUpdate] to proceed to real session
35:48,906 DEBUG AbstractSaveEventListener:489 - transient instance of: hibtest.ObjectRoot
35:48,921 DEBUG DefaultSaveOrUpdateEventListener:161 - saving transient instance
35:48,921 DEBUG AbstractSaveEventListener:152 - saving [hibtest.ObjectRoot#<null>]
35:48,921 DEBUG AbstractSaveEventListener:240 - executing insertions
35:48,921 DEBUG Cascade:115 - processing cascade ACTION_SAVE_UPDATE for: hibtest.ObjectRoot
35:48,937 DEBUG Cascade:150 - done processing cascade ACTION_SAVE_UPDATE for: hibtest.ObjectRoot
35:48,968 DEBUG WrapVisitor:87 - Wrapped collection in role: hibtest.ObjectRoot.aList
35:48,984 DEBUG WrapVisitor:87 - Wrapped collection in role: hibtest.ObjectRoot.bList
35:48,984 DEBUG AbstractSaveEventListener:289 - executing identity-insert immediately
35:48,984 DEBUG AbstractEntityPersister:2079 - Inserting entity: hibtest.ObjectRoot (native id)
35:48,984 DEBUG AbstractBatcher:358 - about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
35:48,984 DEBUG AbstractBatcher:476 - preparing statement
35:49,000 DEBUG AbstractEntityPersister:1927 - Dehydrating entity: [hibtest.ObjectRoot#<null>]
35:49,015 DEBUG AbstractBatcher:366 - about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
35:49,015 DEBUG AbstractBatcher:525 - closing statement
35:49,015 DEBUG AbstractBatcher:358 - about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
35:49,015 DEBUG AbstractBatcher:476 - preparing statement
35:49,015 DEBUG IdentifierGeneratorFactory:37 - Natively generated identity: 3
35:49,015 DEBUG AbstractBatcher:366 - about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
35:49,015 DEBUG AbstractBatcher:525 - closing statement
35:49,031 DEBUG Cascade:115 - processing cascade ACTION_SAVE_UPDATE for: hibtest.ObjectRoot
35:49,031 DEBUG Cascade:291 - cascade ACTION_SAVE_UPDATE for collection: hibtest.ObjectRoot.aList
35:49,031 DEBUG CascadingAction:216 - cascading to saveOrUpdate: hibtest.A
35:49,031 DEBUG AbstractSaveEventListener:489 - transient instance of: hibtest.A
35:49,031 DEBUG DefaultSaveOrUpdateEventListener:161 - saving transient instance
35:49,031 DEBUG AbstractSaveEventListener:152 - saving [hibtest.A#<null>]
35:49,031 DEBUG AbstractSaveEventListener:240 - executing insertions
35:49,046 DEBUG Cascade:115 - processing cascade ACTION_SAVE_UPDATE for: hibtest.A
35:49,046 DEBUG CascadingAction:216 - cascading to saveOrUpdate: hibtest.B
35:49,046 DEBUG AbstractSaveEventListener:489 - transient instance of: hibtest.B
35:49,046 DEBUG DefaultSaveOrUpdateEventListener:161 - saving transient instance
35:49,046 DEBUG AbstractSaveEventListener:152 - saving [hibtest.B#<null>]
35:49,046 DEBUG AbstractSaveEventListener:240 - executing insertions
35:49,046 DEBUG Cascade:115 - processing cascade ACTION_SAVE_UPDATE for: hibtest.B
35:49,046 DEBUG Cascade:150 - done processing cascade ACTION_SAVE_UPDATE for: hibtest.B
35:49,062 DEBUG WrapVisitor:87 - Wrapped collection in role: hibtest.B.aList
35:49,062 DEBUG AbstractSaveEventListener:289 - executing identity-insert immediately
35:49,062 DEBUG AbstractEntityPersister:2079 - Inserting entity: hibtest.B (native id)
35:49,078 DEBUG AbstractBatcher:358 - about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
35:49,078 DEBUG AbstractBatcher:476 - preparing statement
35:49,078 DEBUG AbstractEntityPersister:1927 - Dehydrating entity: [hibtest.B#<null>]
35:49,078 DEBUG AbstractBatcher:366 - about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
35:49,078 DEBUG AbstractBatcher:525 - closing statement
35:49,078 DEBUG AbstractBatcher:358 - about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
35:49,078 DEBUG AbstractBatcher:476 - preparing statement
35:49,078 DEBUG IdentifierGeneratorFactory:37 - Natively generated identity: 3
35:49,078 DEBUG AbstractBatcher:366 - about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
35:49,078 DEBUG AbstractBatcher:525 - closing statement
35:49,093 DEBUG Cascade:115 - processing cascade ACTION_SAVE_UPDATE for: hibtest.B
35:49,093 DEBUG Cascade:291 - cascade ACTION_SAVE_UPDATE for collection: hibtest.B.aList
35:49,093 DEBUG CascadingAction:216 - cascading to saveOrUpdate: hibtest.A
35:49,093 DEBUG AbstractSaveEventListener:463 - persistent instance of: hibtest.A
35:49,093 DEBUG DefaultSaveOrUpdateEventListener:105 - ignoring persistent instance
35:49,093 DEBUG DefaultSaveOrUpdateEventListener:142 - object already associated with session: [hibtest.A#<null>]
35:49,093 DEBUG CascadingAction:216 - cascading to saveOrUpdate: hibtest.A
35:49,093 DEBUG AbstractSaveEventListener:489 - transient instance of: hibtest.A
35:49,109 DEBUG DefaultSaveOrUpdateEventListener:161 - saving transient instance
35:49,109 DEBUG AbstractSaveEventListener:152 - saving [hibtest.A#<null>]
35:49,109 DEBUG AbstractSaveEventListener:240 - executing insertions
35:49,109 DEBUG Cascade:115 - processing cascade ACTION_SAVE_UPDATE for: hibtest.A
35:49,109 DEBUG CascadingAction:216 - cascading to saveOrUpdate: hibtest.B
35:49,109 DEBUG AbstractSaveEventListener:463 - persistent instance of: hibtest.B
35:49,109 DEBUG DefaultSaveOrUpdateEventListener:105 - ignoring persistent instance
35:49,109 DEBUG DefaultSaveOrUpdateEventListener:142 - object already associated with session: [hibtest.B#3]
35:49,109 DEBUG Cascade:150 - done processing cascade ACTION_SAVE_UPDATE for: hibtest.A
35:49,140 DEBUG AbstractSaveEventListener:289 - executing identity-insert immediately
35:49,140 DEBUG AbstractEntityPersister:2079 - Inserting entity: hibtest.A (native id)
35:49,140 DEBUG AbstractBatcher:358 - about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
35:49,140 DEBUG AbstractBatcher:476 - preparing statement
35:49,171 DEBUG AbstractEntityPersister:1927 - Dehydrating entity: [hibtest.A#<null>]
35:49,171 DEBUG AbstractBatcher:366 - about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
35:49,171 DEBUG AbstractBatcher:525 - closing statement
35:49,171 DEBUG AbstractBatcher:358 - about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
35:49,171 DEBUG AbstractBatcher:476 - preparing statement
35:49,171 DEBUG IdentifierGeneratorFactory:37 - Natively generated identity: 5
35:49,203 DEBUG AbstractBatcher:366 - about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
35:49,203 DEBUG AbstractBatcher:525 - closing statement
35:49,203 DEBUG Cascade:115 - processing cascade ACTION_SAVE_UPDATE for: hibtest.A
35:49,203 DEBUG Cascade:150 - done processing cascade ACTION_SAVE_UPDATE for: hibtest.A
35:49,203 DEBUG CascadingAction:216 - cascading to saveOrUpdate: hibtest.A
35:49,203 DEBUG AbstractSaveEventListener:489 - transient instance of: hibtest.A
35:49,203 DEBUG DefaultSaveOrUpdateEventListener:161 - saving transient instance
35:49,203 DEBUG AbstractSaveEventListener:152 - saving [hibtest.A#<null>]
35:49,218 DEBUG AbstractSaveEventListener:240 - executing insertions
35:49,218 DEBUG Cascade:115 - processing cascade ACTION_SAVE_UPDATE for: hibtest.A
35:49,218 DEBUG CascadingAction:216 - cascading to saveOrUpdate: hibtest.B
35:49,218 DEBUG AbstractSaveEventListener:463 - persistent instance of: hibtest.B
35:49,218 DEBUG DefaultSaveOrUpdateEventListener:105 - ignoring persistent instance
35:49,218 DEBUG DefaultSaveOrUpdateEventListener:142 - object already associated with session: [hibtest.B#3]
35:49,218 DEBUG Cascade:150 - done processing cascade ACTION_SAVE_UPDATE for: hibtest.A
35:49,234 DEBUG AbstractSaveEventListener:289 - executing identity-insert immediately
35:49,250 DEBUG AbstractEntityPersister:2079 - Inserting entity: hibtest.A (native id)
35:49,250 DEBUG AbstractBatcher:358 - about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
35:49,250 DEBUG AbstractBatcher:476 - preparing statement
35:49,250 DEBUG AbstractEntityPersister:1927 - Dehydrating entity: [hibtest.A#<null>]
35:49,250 DEBUG AbstractBatcher:366 - about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
35:49,250 DEBUG AbstractBatcher:525 - closing statement
35:49,250 DEBUG AbstractBatcher:358 - about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
35:49,250 DEBUG AbstractBatcher:476 - preparing statement
35:49,250 DEBUG IdentifierGeneratorFactory:37 - Natively generated identity: 6
35:49,265 DEBUG AbstractBatcher:366 - about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
35:49,265 DEBUG AbstractBatcher:525 - closing statement
35:49,265 DEBUG Cascade:115 - processing cascade ACTION_SAVE_UPDATE for: hibtest.A
35:49,265 DEBUG Cascade:150 - done processing cascade ACTION_SAVE_UPDATE for: hibtest.A
35:49,265 DEBUG Cascade:306 - done cascade ACTION_SAVE_UPDATE for collection: hibtest.B.aList
35:50,984 DEBUG Cascade:317 - deleting orphans for collection: hibtest.B.aList
37:11,312  INFO SessionFactoryImpl:767 - closing
37:11,312  INFO DriverManagerConnectionProvider:147 - cleaning up connection pool: jdbc:hsqldb:file:hibtestdb

Top

abCOGhi1

Post subject: Re: Transient problem: Bidirectional cascade all-delete-orph

Posted: Tue Jan 09, 2007 10:33 am

Newbie

Joined: Fri Jan 05, 2007 8:34 am
Posts: 3

I've done some further investigation (stepped through the code) on this and it seems that most of the cascading happens after the objects are inserted. This doesn't happen for the first A object that has a single reference to B. Hibernate sees this as a foreign key that needs to be inserted first. Unfortunately the cascading from B tries to insert the A objects that it refers to - including the first A that was higher up the cascade.

The other A objects can be allocated an id, but that first A is marked as persistent already.

This seems like a timing issue. Is this a bug or have I just missed something in the configuration?

In the meantime there is a workaround. If I change the aList and bList mapping elements round in the ObjectRoot mapping document then the cascade happens in such an order that this problem doesn't occur.

Once again, any help appreciated.

Top

Page 1 of 1

[ 3 posts ]

Board index » Hibernate & Java Persistence » Hibernate Users

All times are UTC - 5 hours [ DST ]

You cannot post new topics in this forum
You cannot reply to topics in this forum
You cannot edit your posts in this forum
You cannot delete your posts in this forum