Hi All, reposted as Anthony suggested. I have tried to simplify the code & just created two basic classes a Parent & a Child. What I am having problems with is why the second test fails. The only difference with the second test (
testFails()) is that I do not reload the Parent from the database before removing the Child from the collection. The test then fails at
assertNull(child2) thus indicating that the cascade-delete-orphan has not worked. I do not understand why I should need to reload the Parent here, it seems a bit of an expensive thing to have to do. I am sure I must be doing something wrong here, but can't work out what or why.
Many thanks for any help :-)
Paul
addChild method from Parent. All other Parent & Child methods are plain getters & setters.
Code:
public void addChild(Child child) {
this.children.add(child);
child.setParent(this);
}
Hibernate version:2.1.6
Mapping documents:Code:
<?xml version="1.0"?>
<!DOCTYPE hibernate-mapping PUBLIC
"-//Hibernate/Hibernate Mapping DTD 2.0//EN"
"http://hibernate.sourceforge.net/hibernate-mapping-2.0.dtd">
<hibernate-mapping>
<class name="Parent" table="PARENT">
<id name="hibernateId" type="long" column="HIBERNATE_ID">
<meta attribute="scope-set">protected</meta>
<generator class="native"/>
</id>
<version name="version" column="VERSION"/>
<property name="pk" type="long">
<column name="PK" not-null="true"/>
</property>
<set name="children" table="CHILD" cascade="all-delete-orphan" inverse="true">
<key column="PARENT_ID"/>
<one-to-many class="Child"/>
</set>
</class>
Code:
<?xml version="1.0"?>
<!DOCTYPE hibernate-mapping PUBLIC
"-//Hibernate/Hibernate Mapping DTD 2.0//EN"
"http://hibernate.sourceforge.net/hibernate-mapping-2.0.dtd">
<hibernate-mapping>
<class name="Child" table="CHILD">
<id name="hibernateId" type="long" column="HIBERNATE_ID">
<meta attribute="scope-set">protected</meta>
<generator class="native"/>
</id>
<version name="version" column="VERSION"/>
<property name="pk" type="long">
<column name="PK" not-null="true"/>
</property>
<many-to-one name="parent" class="Parent" column="PARENT_ID" not-null="true"/>
</class>
</hibernate-mapping>
</hibernate-mapping>
Code between sessionFactory.openSession() and session.close():Posting whole test case here as this contains all the Hibernate code and the testsCode:
public class DetachedPersistenceTestTest extends TestCase {
private static final Long PARENT_ID = new Long(1);
private static final Long CHILD_ID = new Long(1);
private static SessionFactory factory = null;
protected void tearDown() throws Exception {
Parent parent = null;
try {
parent = (Parent) findByPk(PARENT_ID,Parent.class);
} catch (HibernateException e) {
System.out.println("Unable to delete parent");
e.printStackTrace();
throw e;
}
deleteObject(parent);
}
public void testSuccessful() throws Exception {
Parent parent = new Parent(PARENT_ID);
saveObject(parent);
Parent parent2 = (Parent) findByPk(PARENT_ID,Parent.class);
Child child = new Child(CHILD_ID);
parent2.addChild(child);
saveObject(child);
assertTrue(parent2.getChildren().contains(child));
Parent parent3 = (Parent) findByPk(PARENT_ID, Parent.class);
assertTrue(parent3.getChildren().remove(child));
saveObject(parent3);
Child child2 = (Child) findByPk(CHILD_ID, Child.class);
assertNull(child2);
}
public void testFails() throws Exception {
Parent parent = new Parent(PARENT_ID);
saveObject(parent);
Parent parent2 = (Parent) findByPk(PARENT_ID,Parent.class);
Child child = new Child(CHILD_ID);
parent2.addChild(child);
saveObject(child);
assertTrue(parent2.getChildren().contains(child));
// this is the only difference in this test the Parent is not reloaded before removing the Child
// Parent parent3 = (Parent) findByPk(PARENT_ID, Parent.class);
assertTrue(parent2.getChildren().remove(child));
saveObject(parent2);
Child child2 = (Child) findByPk(CHILD_ID, Child.class);
assertNull(child2); // test fails here
}
public SessionFactory getSessionFactory() throws HibernateException {
if (factory == null) {
factory = new Configuration().configure().buildSessionFactory();
}
return factory;
}
public Session openSession() throws HibernateException {
return getSessionFactory().openSession();
}
public void saveObject(Object ob) throws HibernateException {
Session session = null;
Transaction tx = null;
try {
session = openSession();
tx = session.beginTransaction();
session.saveOrUpdate(ob);
tx.commit();
} catch (HibernateException e) {
e.printStackTrace();
if (tx != null) {
tx.rollback();
}
} finally {
session.close();
}
}
public Object findByPk(Long pk, Class type) throws HibernateException {
Session session = null;
try {
session = openSession();
Criteria criteria = session.createCriteria(type);
criteria.add(Expression.eq("pk", pk));
return criteria.uniqueResult();
} finally {
session.close();
}
}
public void deleteObject(Object ob) throws HibernateException {
Session session = null;
Transaction tx = null;
try {
session = openSession();
tx = session.beginTransaction();
session.delete(ob);
tx.commit();
} catch (HibernateException e) {
if (tx != null) {
tx.rollback();
}
} finally {
session.close();
}
}
}
Full stack trace of any exception that occurs:
N/A
Name and version of the database you are using:
MySQL 4.0
The generated SQL (show_sql=true):
For successful test
Hibernate: insert into PARENT (VERSION, PK) values (?, ?)
Hibernate: select this.HIBERNATE_ID as HIBERNAT1_0_, this.VERSION as VERSION0_, this.PK as PK0_ from PARENT this where this.PK=?
Hibernate: select children0_.PARENT_ID as PARENT_ID__, children0_.HIBERNATE_ID as HIBERNAT1___, children0_.HIBERNATE_ID as HIBERNAT1_0_, children0_.VERSION as VERSION0_, children0_.PK as PK0_, children0_.PARENT_ID as PARENT_ID0_ from CHILD children0_ where children0_.PARENT_ID=?
Hibernate: insert into CHILD (VERSION, PK, PARENT_ID) values (?, ?, ?)
Hibernate: select this.HIBERNATE_ID as HIBERNAT1_0_, this.VERSION as VERSION0_, this.PK as PK0_ from PARENT this where this.PK=?
Hibernate: select children0_.PARENT_ID as PARENT_ID__, children0_.HIBERNATE_ID as HIBERNAT1___, children0_.HIBERNATE_ID as HIBERNAT1_0_, children0_.VERSION as VERSION0_, children0_.PK as PK0_, children0_.PARENT_ID as PARENT_ID0_ from CHILD children0_ where children0_.PARENT_ID=?
Hibernate: update PARENT set VERSION=?, PK=? where HIBERNATE_ID=? and VERSION=?
Hibernate: delete from CHILD where HIBERNATE_ID=? and VERSION=?
Hibernate: select this.HIBERNATE_ID as HIBERNAT1_1_, this.VERSION as VERSION1_, this.PK as PK1_, this.PARENT_ID as PARENT_ID1_, parent1_.HIBERNATE_ID as HIBERNAT1_0_, parent1_.VERSION as VERSION0_, parent1_.PK as PK0_ from CHILD this left outer join PARENT parent1_ on this.PARENT_ID=parent1_.HIBERNATE_ID where this.PK=?
Hibernate: select this.HIBERNATE_ID as HIBERNAT1_0_, this.VERSION as VERSION0_, this.PK as PK0_ from PARENT this where this.PK=?
Hibernate: select children0_.PARENT_ID as PARENT_ID__, children0_.HIBERNATE_ID as HIBERNAT1___, children0_.HIBERNATE_ID as HIBERNAT1_0_, children0_.VERSION as VERSION0_, children0_.PK as PK0_, children0_.PARENT_ID as PARENT_ID0_ from CHILD children0_ where children0_.PARENT_ID=?
Hibernate: delete from PARENT where HIBERNATE_ID=? and VERSION=?
For failing test
Hibernate: insert into PARENT (VERSION, PK) values (?, ?)
Hibernate: select this.HIBERNATE_ID as HIBERNAT1_0_, this.VERSION as VERSION0_, this.PK as PK0_ from PARENT this where this.PK=?
Hibernate: select children0_.PARENT_ID as PARENT_ID__, children0_.HIBERNATE_ID as HIBERNAT1___, children0_.HIBERNATE_ID as HIBERNAT1_0_, children0_.VERSION as VERSION0_, children0_.PK as PK0_, children0_.PARENT_ID as PARENT_ID0_ from CHILD children0_ where children0_.PARENT_ID=?
Hibernate: insert into CHILD (VERSION, PK, PARENT_ID) values (?, ?, ?)
Hibernate: update PARENT set VERSION=?, PK=? where HIBERNATE_ID=? and VERSION=?
Hibernate: select this.HIBERNATE_ID as HIBERNAT1_1_, this.VERSION as VERSION1_, this.PK as PK1_, this.PARENT_ID as PARENT_ID1_, parent1_.HIBERNATE_ID as HIBERNAT1_0_, parent1_.VERSION as VERSION0_, parent1_.PK as PK0_ from CHILD this left outer join PARENT parent1_ on this.PARENT_ID=parent1_.HIBERNATE_ID where this.PK=?
Hibernate: select children0_.PARENT_ID as PARENT_ID__, children0_.HIBERNATE_ID as HIBERNAT1___, children0_.HIBERNATE_ID as HIBERNAT1_0_, children0_.VERSION as VERSION0_, children0_.PK as PK0_, children0_.PARENT_ID as PARENT_ID0_ from CHILD children0_ where children0_.PARENT_ID=?
Hibernate: select this.HIBERNATE_ID as HIBERNAT1_0_, this.VERSION as VERSION0_, this.PK as PK0_ from PARENT this where this.PK=?
Hibernate: select children0_.PARENT_ID as PARENT_ID__, children0_.HIBERNATE_ID as HIBERNAT1___, children0_.HIBERNATE_ID as HIBERNAT1_0_, children0_.VERSION as VERSION0_, children0_.PK as PK0_, children0_.PARENT_ID as PARENT_ID0_ from CHILD children0_ where children0_.PARENT_ID=?
Hibernate: delete from CHILD where HIBERNATE_ID=? and VERSION=?
Hibernate: delete from PARENT where HIBERNATE_ID=? and VERSION=?
Debug level Hibernate log excerpt:
For failing test
17-10-2004 20:58:42 INFO - Hibernate 2.1.6 (Environment.java:469)
17-10-2004 20:58:42 INFO - hibernate.properties not found (Environment.java:498)
17-10-2004 20:58:42 INFO - using CGLIB reflection optimizer (Environment.java:529)
17-10-2004 20:58:42 INFO - configuring from resource: /hibernate.cfg.xml (Configuration.java:895)
17-10-2004 20:58:42 INFO - Configuration resource: /hibernate.cfg.xml (Configuration.java:867)
17-10-2004 20:58:42 DEBUG - trying to locate
http://hibernate.sourceforge.net/hibern ... on-2.0.dtd in classpath under net/sf/hibernate/ (DTDEntityResolver.java:20)
17-10-2004 20:58:42 DEBUG - found
http://hibernate.sourceforge.net/hibern ... on-2.0.dtd in classpath (DTDEntityResolver.java:29)
17-10-2004 20:58:42 DEBUG - show_sql=true (Configuration.java:853)
17-10-2004 20:58:42 DEBUG - connection.driver_class=com.mysql.jdbc.Driver (Configuration.java:853)
17-10-2004 20:58:42 DEBUG - dialect=net.sf.hibernate.dialect.MySQLDialect (Configuration.java:853)
17-10-2004 20:58:42 DEBUG - connection.url=jdbc:mysql://127.0.0.1:3306/pttest (Configuration.java:853)
17-10-2004 20:58:42 DEBUG - connection.username=root (Configuration.java:853)
17-10-2004 20:58:42 DEBUG - connection.password= (Configuration.java:853)
17-10-2004 20:58:42 DEBUG - null<-org.dom4j.tree.DefaultAttribute@1d80e6d [Attribute: name resource value "Parent.hbm.xml"] (Configuration.java:1012)
17-10-2004 20:58:42 INFO - Mapping resource: Parent.hbm.xml (Configuration.java:331)
17-10-2004 20:58:42 DEBUG - trying to locate
http://hibernate.sourceforge.net/hibern ... ng-2.0.dtd in classpath under net/sf/hibernate/ (DTDEntityResolver.java:20)
17-10-2004 20:58:42 DEBUG - found
http://hibernate.sourceforge.net/hibern ... ng-2.0.dtd in classpath (DTDEntityResolver.java:29)
17-10-2004 20:58:42 INFO - Mapping class: Parent -> PARENT (Binder.java:229)
17-10-2004 20:58:43 DEBUG - Mapped property: hibernateId -> HIBERNATE_ID, type: long (Binder.java:486)
17-10-2004 20:58:43 DEBUG - Mapped property: version -> VERSION, type: integer (Binder.java:486)
17-10-2004 20:58:43 DEBUG - Mapped property: pk -> PK, type: long (Binder.java:486)
17-10-2004 20:58:43 DEBUG - Mapped property: children, type: java.util.Set (Binder.java:486)
17-10-2004 20:58:43 DEBUG - null<-org.dom4j.tree.DefaultAttribute@12be1bd [Attribute: name resource value "Child.hbm.xml"] (Configuration.java:1012)
17-10-2004 20:58:43 INFO - Mapping resource: Child.hbm.xml (Configuration.java:331)
17-10-2004 20:58:43 DEBUG - trying to locate
http://hibernate.sourceforge.net/hibern ... ng-2.0.dtd in classpath under net/sf/hibernate/ (DTDEntityResolver.java:20)
17-10-2004 20:58:43 DEBUG - found
http://hibernate.sourceforge.net/hibern ... ng-2.0.dtd in classpath (DTDEntityResolver.java:29)
17-10-2004 20:58:43 INFO - Mapping class: Child -> CHILD (Binder.java:229)
17-10-2004 20:58:43 DEBUG - Mapped property: hibernateId -> HIBERNATE_ID, type: long (Binder.java:486)
17-10-2004 20:58:43 DEBUG - Mapped property: version -> VERSION, type: integer (Binder.java:486)
17-10-2004 20:58:43 DEBUG - Mapped property: pk -> PK, type: long (Binder.java:486)
17-10-2004 20:58:43 DEBUG - Mapped property: parent -> PARENT_ID, type: Parent (Binder.java:486)
17-10-2004 20:58:43 INFO - Configured SessionFactory: null (Configuration.java:1053)
17-10-2004 20:58:43 DEBUG - properties: {hibernate.connection.password=, java.runtime.name=Java(TM) 2 Runtime Environment, Standard Edition, sun.boot.library.path=D:\j2sdk1.4.2_01\jre\bin, java.vm.version=1.4.2_01-b06, hibernate.connection.username=root, java.vm.vendor=Sun Microsystems Inc., java.vendor.url=http://java.sun.com/, path.separator=;, java.vm.name=Java HotSpot(TM) Client VM, file.encoding.pkg=sun.io, idea.launcher.port=7537, user.country=GB, sun.os.patch.level=Service Pack 1, java.vm.specification.name=Java Virtual Machine Specification, user.dir=D:\java_dev\Test_project, java.runtime.version=1.4.2_01-b06, java.awt.graphicsenv=sun.awt.Win32GraphicsEnvironment, java.endorsed.dirs=D:\j2sdk1.4.2_01\jre\lib\endorsed, os.arch=x86, java.io.tmpdir=C:\DOCUME~1\Paul\LOCALS~1\Temp\, line.separator=
, java.vm.specification.vendor=Sun Microsystems Inc., user.variant=, os.name=Windows XP, sun.java2d.fontpath=, java.library.path=D:\j2sdk1.4.2_01\bin;.;C:\WINDOWS\System32;C:\WINDOWS;D:\Perl\bin\;C:\WINDOWS\system32;C:\WINDOWS;C:\WINDOWS\System32\Wbem;D:\apache-ant-1.5.4\bin;D:\j2sdk1.4.2_01\bin;D:\j2sdkee1.3.1\bin;D:\gpg, java.specification.name=Java Platform API Specification, java.class.version=48.0, java.util.prefs.PreferencesFactory=java.util.prefs.WindowsPreferencesFactory, os.version=5.1, connection.password=, user.home=C:\Documents and Settings\Paul, user.timezone=Europe/London, connection.username=root, java.awt.printerjob=sun.awt.windows.WPrinterJob, file.encoding=windows-1252, java.specification.version=1.4, hibernate.connection.driver_class=com.mysql.jdbc.Driver, show_sql=true, user.name=Paul, java.class.path=D:\j2sdk1.4.2_01\jre\lib\charsets.jar;D:\j2sdk1.4.2_01\jre\lib\jce.jar;D:\j2sdk1.4.2_01\jre\lib\jsse.jar;D:\j2sdk1.4.2_01\jre\lib\plugin.jar;D:\j2sdk1.4.2_01\jre\lib\rt.jar;D:\j2sdk1.4.2_01\jre\lib\sunrsasign.jar;D:\j2sdk1.4.2_01\jre\lib\ext\dnsns.jar;D:\j2sdk1.4.2_01\jre\lib\ext\ldapsec.jar;D:\j2sdk1.4.2_01\jre\lib\ext\localedata.jar;D:\j2sdk1.4.2_01\jre\lib\ext\sunjce_provider.jar;D:\java_dev\Test_project\classes;D:\Apache Software Foundation\Tomcat 5.0\common\lib\mysql-connector-java-3.0.8-stable-bin.jar;D:\java_dev\easy-lists-hibernate\lib;D:\java_dev\Test_project\etc;D:\java_dev\easy-lists-hibernate\lib\bluesoup.jar;D:\java_dev\easy-lists-hibernate\lib\ant-1.5.3.jar;D:\java_dev\easy-lists-hibernate\lib\jdom.jar;D:\java_dev\easy-lists-hibernate\lib\ant-optional-1.5.3.jar;D:\java_dev\easy-lists-hibernate\lib\commons-lang-1.0.1.jar;D:\java_dev\easy-lists-hibernate\lib\jta.jar;D:\java_dev\easy-lists-hibernate\lib\commons-dbcp-1.2.1.jar;D:\java_dev\easy-lists-hibernate\lib\ehcache-0.9.jar;D:\java_dev\easy-lists-hibernate\lib\hibernate2.jar;D:\java_dev\easy-lists-hibernate\lib\dom4j-1.4.jar;D:\java_dev\easy-lists-hibernate\lib\aspectjrt-1.1.1.jar;D:\java_dev\easy-lists-hibernate\lib\odmg-3.0.jar;D:\java_dev\easy-lists-hibernate\lib\httpunit.jar;D:\java_dev\easy-lists-hibernate\lib\js.jar;D:\java_dev\easy-lists-hibernate\lib\commons-collections-2.1.1.jar;D:\java_dev\easy-lists-hibernate\lib\xmlParserAPIs.jar;D:\java_dev\easy-lists-hibernate\lib\hibernate-tools.jar;D:\java_dev\easy-lists-hibernate\lib\log4j-1.2.8.jar;D:\java_dev\easy-lists-hibernate\lib\junit-3.8.1.jar;D:\java_dev\easy-lists-hibernate\lib\cglib-full-2.0.2.jar;D:\java_dev\easy-lists-hibernate\lib\nekohtml.jar;D:\java_dev\easy-lists-hibernate\lib\Tidy.jar;D:\java_dev\easy-lists-hibernate\lib\xercesImpl.jar;D:\java_dev\easy-lists-hibernate\lib\commons-logging-1.0.4.jar;D:\java_dev\easy-lists-hibernate\lib\concurrent-1.3.3.jar;D:\java_dev\easy-lists-hibernate\lib\commons-pool-1.2.jar;D:\java_dev\easy-lists-hibernate\lib\commons-httpclient-2.0.jar;D:\java_dev\easy-lists-hibernate\lib\xml-apis.jar;D:\java_dev\easy-lists-hibernate\lib\cactus-1.6.1.jar;D:\IntelliJ-IDEA-4.5\lib\idea_rt.jar, hibernate.show_sql=true, java.vm.specification.version=1.0, java.home=D:\j2sdk1.4.2_01\jre, sun.arch.data.model=32, hibernate.connection.url=jdbc:mysql://127.0.0.1:3306/pttest, hibernate.dialect=net.sf.hibernate.dialect.MySQLDialect, user.language=en, java.specification.vendor=Sun Microsystems Inc., awt.toolkit=sun.awt.windows.WToolkit, hibernate.cglib.use_reflection_optimizer=true, java.vm.info=mixed mode, java.version=1.4.2_01, java.ext.dirs=D:\j2sdk1.4.2_01\jre\lib\ext, sun.boot.class.path=D:\j2sdk1.4.2_01\jre\lib\rt.jar;D:\j2sdk1.4.2_01\jre\lib\i18n.jar;D:\j2sdk1.4.2_01\jre\lib\sunrsasign.jar;D:\j2sdk1.4.2_01\jre\lib\jsse.jar;D:\j2sdk1.4.2_01\jre\lib\jce.jar;D:\j2sdk1.4.2_01\jre\lib\charsets.jar;D:\j2sdk1.4.2_01\jre\classes, java.vendor=Sun Microsystems Inc., connection.driver_class=com.mysql.jdbc.Driver, file.separator=\, idea.launcher.library=D:\IntelliJ-IDEA-4.5\bin\breakgen.dll, java.vendor.url.bug=http://java.sun.com/cgi-bin/bugreport.cgi, sun.io.unicode.encoding=UnicodeLittle, sun.cpu.endian=little, connection.url=jdbc:mysql://127.0.0.1:3306/pttest, dialect=net.sf.hibernate.dialect.MySQLDialect, sun.cpu.isalist=pentium i486 i386} (Configuration.java:1054)
17-10-2004 20:58:43 INFO - processing one-to-many association mappings (Configuration.java:627)
17-10-2004 20:58:43 DEBUG - Second pass for collection: Parent.children (Binder.java:1353)
17-10-2004 20:58:43 INFO - Mapping collection: Parent.children -> CHILD (Binder.java:1181)
17-10-2004 20:58:43 DEBUG - Mapped collection key: PARENT_ID, one-to-many: Child (Binder.java:1368)
17-10-2004 20:58:43 INFO - processing one-to-one association property references (Configuration.java:636)
17-10-2004 20:58:43 INFO - processing foreign key constraints (Configuration.java:661)
17-10-2004 20:58:43 DEBUG - resolving reference to class: Parent (Configuration.java:678)
17-10-2004 20:58:43 INFO - Using dialect: net.sf.hibernate.dialect.MySQLDialect (Dialect.java:82)
17-10-2004 20:58:43 INFO - Maximim outer join fetch depth: 2 (SettingsFactory.java:59)
17-10-2004 20:58:43 INFO - Use outer join fetching: true (SettingsFactory.java:63)
17-10-2004 20:58:43 INFO - Using Hibernate built-in connection pool (not for production use!) (DriverManagerConnectionProvider.java:42)
17-10-2004 20:58:43 INFO - Hibernate connection pool size: 20 (DriverManagerConnectionProvider.java:43)
17-10-2004 20:58:43 INFO - using driver: com.mysql.jdbc.Driver at URL: jdbc:mysql://127.0.0.1:3306/pttest (DriverManagerConnectionProvider.java:77)
17-10-2004 20:58:43 INFO - connection properties: {user=root, password=} (DriverManagerConnectionProvider.java:78)
17-10-2004 20:58:43 INFO - No TransactionManagerLookup configured (in JTA environment, use of process level read-write cache is not recommended) (TransactionManagerLookupFactory.java:33)
17-10-2004 20:58:43 DEBUG - total checked-out connections: 0 (DriverManagerConnectionProvider.java:84)
17-10-2004 20:58:43 DEBUG - opening new JDBC connection (DriverManagerConnectionProvider.java:100)
17-10-2004 20:58:43 DEBUG - created connection to: jdbc:mysql://127.0.0.1:3306/pttest, Isolation Level: 4 (DriverManagerConnectionProvider.java:106)
17-10-2004 20:58:43 DEBUG - returning connection to pool, pool size: 1 (DriverManagerConnectionProvider.java:120)
17-10-2004 20:58:43 INFO - Use scrollable result sets: true (SettingsFactory.java:103)
17-10-2004 20:58:43 INFO - Use JDBC3 getGeneratedKeys(): true (SettingsFactory.java:106)
17-10-2004 20:58:43 INFO - Optimize cache for minimal puts: false (SettingsFactory.java:109)
17-10-2004 20:58:43 INFO - echoing all SQL to stdout (SettingsFactory.java:115)
17-10-2004 20:58:43 INFO - Query language substitutions: {} (SettingsFactory.java:118)
17-10-2004 20:58:43 INFO - cache provider: net.sf.hibernate.cache.EhCacheProvider (SettingsFactory.java:129)
17-10-2004 20:58:43 INFO - instantiating and configuring caches (Configuration.java:1116)
17-10-2004 20:58:43 INFO - building session factory (SessionFactoryImpl.java:118)
17-10-2004 20:58:43 DEBUG - instantiating session factory with properties: {hibernate.connection.password=, java.runtime.name=Java(TM) 2 Runtime Environment, Standard Edition, sun.boot.library.path=D:\j2sdk1.4.2_01\jre\bin, java.vm.version=1.4.2_01-b06, hibernate.connection.username=root, java.vm.vendor=Sun Microsystems Inc., java.vendor.url=http://java.sun.com/, path.separator=;, java.vm.name=Java HotSpot(TM) Client VM, file.encoding.pkg=sun.io, idea.launcher.port=7537, user.country=GB, sun.os.patch.level=Service Pack 1, java.vm.specification.name=Java Virtual Machine Specification, user.dir=D:\java_dev\Test_project, java.runtime.version=1.4.2_01-b06, java.awt.graphicsenv=sun.awt.Win32GraphicsEnvironment, java.endorsed.dirs=D:\j2sdk1.4.2_01\jre\lib\endorsed, os.arch=x86, java.io.tmpdir=C:\DOCUME~1\Paul\LOCALS~1\Temp\, line.separator=
, java.vm.specification.vendor=Sun Microsystems Inc., user.variant=, os.name=Windows XP, sun.java2d.fontpath=, java.library.path=D:\j2sdk1.4.2_01\bin;.;C:\WINDOWS\System32;C:\WINDOWS;D:\Perl\bin\;C:\WINDOWS\system32;C:\WINDOWS;C:\WINDOWS\System32\Wbem;D:\apache-ant-1.5.4\bin;D:\j2sdk1.4.2_01\bin;D:\j2sdkee1.3.1\bin;D:\gpg, java.specification.name=Java Platform API Specification, java.class.version=48.0, java.util.prefs.PreferencesFactory=java.util.prefs.WindowsPreferencesFactory, os.version=5.1, connection.password=, user.home=C:\Documents and Settings\Paul, user.timezone=Europe/London, connection.username=root, java.awt.printerjob=sun.awt.windows.WPrinterJob, file.encoding=windows-1252, java.specification.version=1.4, hibernate.connection.driver_class=com.mysql.jdbc.Driver, show_sql=true, user.name=Paul, java.class.path=D:\j2sdk1.4.2_01\jre\lib\charsets.jar;D:\j2sdk1.4.2_01\jre\lib\jce.jar;D:\j2sdk1.4.2_01\jre\lib\jsse.jar;D:\j2sdk1.4.2_01\jre\lib\plugin.jar;D:\j2sdk1.4.2_01\jre\lib\rt.jar;D:\j2sdk1.4.2_01\jre\lib\sunrsasign.jar;D:\j2sdk1.4.2_01\jre\lib\ext\dnsns.jar;D:\j2sdk1.4.2_01\jre\lib\ext\ldapsec.jar;D:\j2sdk1.4.2_01\jre\lib\ext\localedata.jar;D:\j2sdk1.4.2_01\jre\lib\ext\sunjce_provider.jar;D:\java_dev\Test_project\classes;D:\Apache Software Foundation\Tomcat 5.0\common\lib\mysql-connector-java-3.0.8-stable-bin.jar;D:\java_dev\easy-lists-hibernate\lib;D:\java_dev\Test_project\etc;D:\java_dev\easy-lists-hibernate\lib\bluesoup.jar;D:\java_dev\easy-lists-hibernate\lib\ant-1.5.3.jar;D:\java_dev\easy-lists-hibernate\lib\jdom.jar;D:\java_dev\easy-lists-hibernate\lib\ant-optional-1.5.3.jar;D:\java_dev\easy-lists-hibernate\lib\commons-lang-1.0.1.jar;D:\java_dev\easy-lists-hibernate\lib\jta.jar;D:\java_dev\easy-lists-hibernate\lib\commons-dbcp-1.2.1.jar;D:\java_dev\easy-lists-hibernate\lib\ehcache-0.9.jar;D:\java_dev\easy-lists-hibernate\lib\hibernate2.jar;D:\java_dev\easy-lists-hibernate\lib\dom4j-1.4.jar;D:\java_dev\easy-lists-hibernate\lib\aspectjrt-1.1.1.jar;D:\java_dev\easy-lists-hibernate\lib\odmg-3.0.jar;D:\java_dev\easy-lists-hibernate\lib\httpunit.jar;D:\java_dev\easy-lists-hibernate\lib\js.jar;D:\java_dev\easy-lists-hibernate\lib\commons-collections-2.1.1.jar;D:\java_dev\easy-lists-hibernate\lib\xmlParserAPIs.jar;D:\java_dev\easy-lists-hibernate\lib\hibernate-tools.jar;D:\java_dev\easy-lists-hibernate\lib\log4j-1.2.8.jar;D:\java_dev\easy-lists-hibernate\lib\junit-3.8.1.jar;D:\java_dev\easy-lists-hibernate\lib\cglib-full-2.0.2.jar;D:\java_dev\easy-lists-hibernate\lib\nekohtml.jar;D:\java_dev\easy-lists-hibernate\lib\Tidy.jar;D:\java_dev\easy-lists-hibernate\lib\xercesImpl.jar;D:\java_dev\easy-lists-hibernate\lib\commons-logging-1.0.4.jar;D:\java_dev\easy-lists-hibernate\lib\concurrent-1.3.3.jar;D:\java_dev\easy-lists-hibernate\lib\commons-pool-1.2.jar;D:\java_dev\easy-lists-hibernate\lib\commons-httpclient-2.0.jar;D:\java_dev\easy-lists-hibernate\lib\xml-apis.jar;D:\java_dev\easy-lists-hibernate\lib\cactus-1.6.1.jar;D:\IntelliJ-IDEA-4.5\lib\idea_rt.jar, hibernate.show_sql=true, java.vm.specification.version=1.0, java.home=D:\j2sdk1.4.2_01\jre, sun.arch.data.model=32, hibernate.connection.url=jdbc:mysql://127.0.0.1:3306/pttest, hibernate.dialect=net.sf.hibernate.dialect.MySQLDialect, user.language=en, java.specification.vendor=Sun Microsystems Inc., awt.toolkit=sun.awt.windows.WToolkit, hibernate.cglib.use_reflection_optimizer=true, java.vm.info=mixed mode, java.version=1.4.2_01, java.ext.dirs=D:\j2sdk1.4.2_01\jre\lib\ext, sun.boot.class.path=D:\j2sdk1.4.2_01\jre\lib\rt.jar;D:\j2sdk1.4.2_01\jre\lib\i18n.jar;D:\j2sdk1.4.2_01\jre\lib\sunrsasign.jar;D:\j2sdk1.4.2_01\jre\lib\jsse.jar;D:\j2sdk1.4.2_01\jre\lib\jce.jar;D:\j2sdk1.4.2_01\jre\lib\charsets.jar;D:\j2sdk1.4.2_01\jre\classes, java.vendor=Sun Microsystems Inc., connection.driver_class=com.mysql.jdbc.Driver, file.separator=\, idea.launcher.library=D:\IntelliJ-IDEA-4.5\bin\breakgen.dll, java.vendor.url.bug=http://java.sun.com/cgi-bin/bugreport.cgi, sun.io.unicode.encoding=UnicodeLittle, sun.cpu.endian=little, connection.url=jdbc:mysql://127.0.0.1:3306/pttest, dialect=net.sf.hibernate.dialect.MySQLDialect, sun.cpu.isalist=pentium i486 i386} (SessionFactoryImpl.java:124)
17-10-2004 20:58:44 DEBUG - initializing class SessionFactoryObjectFactory (SessionFactoryObjectFactory.java:39)
17-10-2004 20:58:44 DEBUG - registered: d2a1cd8bffa8786700ffa8786a040000 (unnamed) (SessionFactoryObjectFactory.java:76)
17-10-2004 20:58:44 INFO - Not binding factory to JNDI, no JNDI name configured (SessionFactoryObjectFactory.java:82)
17-10-2004 20:58:44 DEBUG - instantiated session factory (SessionFactoryImpl.java:195)
17-10-2004 20:58:44 DEBUG - opened session (SessionImpl.java:555)
17-10-2004 20:58:44 DEBUG - begin (JDBCTransaction.java:37)
17-10-2004 20:58:44 DEBUG - total checked-out connections: 0 (DriverManagerConnectionProvider.java:84)
17-10-2004 20:58:44 DEBUG - using pooled JDBC connection, pool size: 0 (DriverManagerConnectionProvider.java:90)
17-10-2004 20:58:44 DEBUG - current autocommit status:false (JDBCTransaction.java:41)
17-10-2004 20:58:44 DEBUG - saveOrUpdate() unsaved instance (SessionImpl.java:1387)
17-10-2004 20:58:44 DEBUG - saving [Parent#<null>] (SessionImpl.java:825)
17-10-2004 20:58:44 DEBUG - executing insertions (SessionImpl.java:2309)
17-10-2004 20:58:44 DEBUG - processing cascades for: Parent (Cascades.java:497)
17-10-2004 20:58:44 DEBUG - done processing cascades for: Parent (Cascades.java:506)
17-10-2004 20:58:44 DEBUG - using initial version: 0 (Versioning.java:56)
17-10-2004 20:58:44 DEBUG - Inserting entity: Parent (native id) (EntityPersister.java:490)
17-10-2004 20:58:44 DEBUG - Version: 0 (EntityPersister.java:491)
17-10-2004 20:58:44 DEBUG - about to open: 0 open PreparedStatements, 0 open ResultSets (BatcherImpl.java:200)
17-10-2004 20:58:44 DEBUG - insert into PARENT (VERSION, PK) values (?, ?) (BatcherImpl.java:226)
17-10-2004 20:58:44 DEBUG - preparing statement (BatcherImpl.java:249)
17-10-2004 20:58:44 DEBUG - Dehydrating entity: [Parent#<null>] (EntityPersister.java:388)
17-10-2004 20:58:44 DEBUG - Natively generated identity: 7 (AbstractEntityPersister.java:1236)
17-10-2004 20:58:44 DEBUG - done closing: 0 open PreparedStatements, 0 open ResultSets (BatcherImpl.java:207)
17-10-2004 20:58:44 DEBUG - closing statement (BatcherImpl.java:269)
17-10-2004 20:58:44 DEBUG - processing cascades for: Parent (Cascades.java:497)
17-10-2004 20:58:44 DEBUG - done processing cascades for: Parent (Cascades.java:506)
17-10-2004 20:58:44 DEBUG - commit (JDBCTransaction.java:59)
17-10-2004 20:58:44 DEBUG - flushing session (SessionImpl.java:2246)
17-10-2004 20:58:44 DEBUG - processing cascades for: Parent (Cascades.java:497)
17-10-2004 20:58:44 DEBUG - done processing cascades for: Parent (Cascades.java:506)
17-10-2004 20:58:44 DEBUG - Flushing entities and processing referenced collections (SessionImpl.java:2439)
17-10-2004 20:58:44 DEBUG - Processing unreferenced collections (SessionImpl.java:2780)
17-10-2004 20:58:44 DEBUG - Scheduling collection removes/(re)creates/updates (SessionImpl.java:2794)
17-10-2004 20:58:44 DEBUG - Flushed: 0 insertions, 0 updates, 0 deletions to 1 objects (SessionImpl.java:2270)
17-10-2004 20:58:44 DEBUG - Flushed: 0 (re)creations, 0 updates, 0 removals to 0 collections (SessionImpl.java:2275)
17-10-2004 20:58:44 DEBUG - listing entities: (Printer.java:75)
17-10-2004 20:58:44 DEBUG - Parent{hibernateId=7, children=null, pk=1, version=0} (Printer.java:82)
17-10-2004 20:58:44 DEBUG - executing flush (SessionImpl.java:2359)
17-10-2004 20:58:44 DEBUG - post flush (SessionImpl.java:2824)
17-10-2004 20:58:44 DEBUG - transaction completion (SessionImpl.java:585)
17-10-2004 20:58:44 DEBUG - closing session (SessionImpl.java:573)
17-10-2004 20:58:44 DEBUG - disconnecting session (SessionImpl.java:3336)
17-10-2004 20:58:44 DEBUG - returning connection to pool, pool size: 1 (DriverManagerConnectionProvider.java:120)
17-10-2004 20:58:44 DEBUG - transaction completion (SessionImpl.java:585)
17-10-2004 20:58:44 DEBUG - opened session (SessionImpl.java:555)
17-10-2004 20:58:44 DEBUG - flushing session (SessionImpl.java:2246)
17-10-2004 20:58:44 DEBUG - Flushing entities and processing referenced collections (SessionImpl.java:2439)
17-10-2004 20:58:44 DEBUG - Processing unreferenced collections (SessionImpl.java:2780)
17-10-2004 20:58:44 DEBUG - Scheduling collection removes/(re)creates/updates (SessionImpl.java:2794)
17-10-2004 20:58:44 DEBUG - Flushed: 0 insertions, 0 updates, 0 deletions to 0 objects (SessionImpl.java:2270)
17-10-2004 20:58:44 DEBUG - Flushed: 0 (re)creations, 0 updates, 0 removals to 0 collections (SessionImpl.java:2275)
17-10-2004 20:58:44 DEBUG - Dont need to execute flush (SessionImpl.java:1818)
17-10-2004 20:58:44 DEBUG - about to open: 0 open PreparedStatements, 0 open ResultSets (BatcherImpl.java:200)
17-10-2004 20:58:44 DEBUG - total checked-out connections: 0 (DriverManagerConnectionProvider.java:84)
17-10-2004 20:58:44 DEBUG - using pooled JDBC connection, pool size: 0 (DriverManagerConnectionProvider.java:90)
17-10-2004 20:58:44 DEBUG - select this.HIBERNATE_ID as HIBERNAT1_0_, this.VERSION as VERSION0_, this.PK as PK0_ from PARENT this where this.PK=? (BatcherImpl.java:226)
17-10-2004 20:58:44 DEBUG - preparing statement (BatcherImpl.java:249)
17-10-2004 20:58:44 DEBUG - processing result set (Loader.java:277)
17-10-2004 20:58:44 DEBUG - result row: 7 (Loader.java:480)
17-10-2004 20:58:44 DEBUG - Initializing object from ResultSet: 7 (Loader.java:611)
17-10-2004 20:58:44 DEBUG - Hydrating entity: Parent#7 (Loader.java:680)
17-10-2004 20:58:44 DEBUG - Version: 0 (SessionImpl.java:1910)
17-10-2004 20:58:44 DEBUG - done processing result set (1 rows) (Loader.java:294)
17-10-2004 20:58:44 DEBUG - done closing: 0 open PreparedStatements, 0 open ResultSets (BatcherImpl.java:207)
17-10-2004 20:58:44 DEBUG - closing statement (BatcherImpl.java:269)
17-10-2004 20:58:44 DEBUG - total objects hydrated: 1 (Loader.java:314)
17-10-2004 20:58:44 DEBUG - resolving associations for [Parent#7] (SessionImpl.java:2202)
17-10-2004 20:58:44 DEBUG - creating collection wrapper:[Parent.children#7] (SessionImpl.java:3933)
17-10-2004 20:58:44 DEBUG - done materializing entity [Parent#7] (SessionImpl.java:2226)
17-10-2004 20:58:44 DEBUG - initializing non-lazy collections (SessionImpl.java:3116)
17-10-2004 20:58:44 DEBUG - initializing collection [Parent.children#7] (SessionImpl.java:3260)
17-10-2004 20:58:44 DEBUG - checking second-level cache (SessionImpl.java:3261)
17-10-2004 20:58:44 DEBUG - collection not cached (SessionImpl.java:3267)
17-10-2004 20:58:44 DEBUG - about to open: 0 open PreparedStatements, 0 open ResultSets (BatcherImpl.java:200)
17-10-2004 20:58:44 DEBUG - select children0_.PARENT_ID as PARENT_ID__, children0_.HIBERNATE_ID as HIBERNAT1___, children0_.HIBERNATE_ID as HIBERNAT1_0_, children0_.VERSION as VERSION0_, children0_.PK as PK0_, children0_.PARENT_ID as PARENT_ID0_ from CHILD children0_ where children0_.PARENT_ID=? (BatcherImpl.java:226)
17-10-2004 20:58:44 DEBUG - preparing statement (BatcherImpl.java:249)
17-10-2004 20:58:44 DEBUG - result set contains (possibly empty) collection: [Parent.children#7] (Loader.java:402)
17-10-2004 20:58:44 DEBUG - uninitialized collection: initializing (SessionImpl.java:3018)
17-10-2004 20:58:44 DEBUG - processing result set (Loader.java:277)
17-10-2004 20:58:44 DEBUG - done processing result set (0 rows) (Loader.java:294)
17-10-2004 20:58:44 DEBUG - done closing: 0 open PreparedStatements, 0 open ResultSets (BatcherImpl.java:207)
17-10-2004 20:58:44 DEBUG - closing statement (BatcherImpl.java:269)
17-10-2004 20:58:44 DEBUG - total objects hydrated: 0 (Loader.java:314)
17-10-2004 20:58:44 DEBUG - 1 collections were found in result set (SessionImpl.java:3077)
17-10-2004 20:58:44 DEBUG - collection fully initialized: [Parent.children#7] (SessionImpl.java:3095)
17-10-2004 20:58:44 DEBUG - 1 collections initialized (SessionImpl.java:3098)
17-10-2004 20:58:44 DEBUG - collection initialized (SessionImpl.java:3269)
17-10-2004 20:58:44 DEBUG - closing session (SessionImpl.java:573)
17-10-2004 20:58:44 DEBUG - disconnecting session (SessionImpl.java:3336)
17-10-2004 20:58:44 DEBUG - returning connection to pool, pool size: 1 (DriverManagerConnectionProvider.java:120)
17-10-2004 20:58:44 DEBUG - transaction completion (SessionImpl.java:585)
17-10-2004 20:58:44 DEBUG - opened session (SessionImpl.java:555)
17-10-2004 20:58:44 DEBUG - begin (JDBCTransaction.java:37)
17-10-2004 20:58:44 DEBUG - total checked-out connections: 0 (DriverManagerConnectionProvider.java:84)
17-10-2004 20:58:44 DEBUG - using pooled JDBC connection, pool size: 0 (DriverManagerConnectionProvider.java:90)
17-10-2004 20:58:44 DEBUG - current autocommit status:false (JDBCTransaction.java:41)
17-10-2004 20:58:44 DEBUG - saveOrUpdate() unsaved instance (SessionImpl.java:1387)
17-10-2004 20:58:44 DEBUG - saving [Child#<null>] (SessionImpl.java:825)
17-10-2004 20:58:44 DEBUG - executing insertions (SessionImpl.java:2309)
17-10-2004 20:58:44 DEBUG - using initial version: 0 (Versioning.java:56)
17-10-2004 20:58:44 DEBUG - version unsaved-value strategy UNDEFINED (Cascades.java:396)
17-10-2004 20:58:44 DEBUG - id unsaved-value strategy NULL (Cascades.java:341)
17-10-2004 20:58:44 DEBUG - Inserting entity: Child (native id) (EntityPersister.java:490)
17-10-2004 20:58:44 DEBUG - Version: 0 (EntityPersister.java:491)
17-10-2004 20:58:44 DEBUG - about to open: 0 open PreparedStatements, 0 open ResultSets (BatcherImpl.java:200)
17-10-2004 20:58:44 DEBUG - insert into CHILD (VERSION, PK, PARENT_ID) values (?, ?, ?) (BatcherImpl.java:226)
17-10-2004 20:58:44 DEBUG - preparing statement (BatcherImpl.java:249)
17-10-2004 20:58:44 DEBUG - Dehydrating entity: [Child#<null>] (EntityPersister.java:388)
17-10-2004 20:58:44 DEBUG - version unsaved-value strategy UNDEFINED (Cascades.java:396)
17-10-2004 20:58:44 DEBUG - id unsaved-value strategy NULL (Cascades.java:341)
17-10-2004 20:58:44 DEBUG - Natively generated identity: 7 (AbstractEntityPersister.java:1236)
17-10-2004 20:58:44 DEBUG - done closing: 0 open PreparedStatements, 0 open ResultSets (BatcherImpl.java:207)
17-10-2004 20:58:44 DEBUG - closing statement (BatcherImpl.java:269)
17-10-2004 20:58:44 DEBUG - commit (JDBCTransaction.java:59)
17-10-2004 20:58:44 DEBUG - flushing session (SessionImpl.java:2246)
17-10-2004 20:58:44 DEBUG - Flushing entities and processing referenced collections (SessionImpl.java:2439)
17-10-2004 20:58:44 DEBUG - Processing unreferenced collections (SessionImpl.java:2780)
17-10-2004 20:58:44 DEBUG - Scheduling collection removes/(re)creates/updates (SessionImpl.java:2794)
17-10-2004 20:58:44 DEBUG - Flushed: 0 insertions, 0 updates, 0 deletions to 1 objects (SessionImpl.java:2270)
17-10-2004 20:58:44 DEBUG - Flushed: 0 (re)creations, 0 updates, 0 removals to 0 collections (SessionImpl.java:2275)
17-10-2004 20:58:44 DEBUG - listing entities: (Printer.java:75)
17-10-2004 20:58:44 DEBUG - Child{hibernateId=7, parent=Parent#7, pk=1, version=0} (Printer.java:82)
17-10-2004 20:58:44 DEBUG - executing flush (SessionImpl.java:2359)
17-10-2004 20:58:44 DEBUG - post flush (SessionImpl.java:2824)
17-10-2004 20:58:44 DEBUG - transaction completion (SessionImpl.java:585)
17-10-2004 20:58:44 DEBUG - closing session (SessionImpl.java:573)
17-10-2004 20:58:44 DEBUG - disconnecting session (SessionImpl.java:3336)
17-10-2004 20:58:44 DEBUG - returning connection to pool, pool size: 1 (DriverManagerConnectionProvider.java:120)
17-10-2004 20:58:44 DEBUG - transaction completion (SessionImpl.java:585)
17-10-2004 20:58:44 DEBUG - opened session (SessionImpl.java:555)
17-10-2004 20:58:44 DEBUG - begin (JDBCTransaction.java:37)
17-10-2004 20:58:44 DEBUG - total checked-out connections: 0 (DriverManagerConnectionProvider.java:84)
17-10-2004 20:58:44 DEBUG - using pooled JDBC connection, pool size: 0 (DriverManagerConnectionProvider.java:90)
17-10-2004 20:58:44 DEBUG - current autocommit status:false (JDBCTransaction.java:41)
17-10-2004 20:58:44 DEBUG - version unsaved-value strategy UNDEFINED (Cascades.java:396)
17-10-2004 20:58:44 DEBUG - id unsaved-value strategy NULL (Cascades.java:341)
17-10-2004 20:58:44 DEBUG - saveOrUpdate() previously saved instance with id: 7 (SessionImpl.java:1392)
17-10-2004 20:58:44 DEBUG - updating [Parent#7] (SessionImpl.java:1440)
17-10-2004 20:58:44 DEBUG - running Session.finalize() (SessionImpl.java:3388)
17-10-2004 20:58:44 DEBUG - processing cascades for: Parent (Cascades.java:497)
17-10-2004 20:58:44 DEBUG - cascading to collection: Parent.children (Cascades.java:524)
17-10-2004 20:58:44 DEBUG - done processing cascades for: Parent (Cascades.java:506)
17-10-2004 20:58:44 DEBUG - commit (JDBCTransaction.java:59)
17-10-2004 20:58:44 DEBUG - flushing session (SessionImpl.java:2246)
17-10-2004 20:58:44 DEBUG - processing cascades for: Parent (Cascades.java:497)
17-10-2004 20:58:44 DEBUG - cascading to collection: Parent.children (Cascades.java:524)
17-10-2004 20:58:44 DEBUG - done processing cascades for: Parent (Cascades.java:506)
17-10-2004 20:58:44 DEBUG - running Session.finalize() (SessionImpl.java:3388)
17-10-2004 20:58:44 DEBUG - Collection dirty: [Parent.children#7] (SessionImpl.java:342)
17-10-2004 20:58:44 DEBUG - Flushing entities and processing referenced collections (SessionImpl.java:2439)
17-10-2004 20:58:44 DEBUG - Updating entity: [Parent#7] (SessionImpl.java:2533)
17-10-2004 20:58:44 DEBUG - Incrementing: 0 to 1 (Versioning.java:26)
17-10-2004 20:58:44 DEBUG - Collection found: [Parent.children#7], was: [Parent.children#7] (SessionImpl.java:2884)
17-10-2004 20:58:44 DEBUG - Processing unreferenced collections (SessionImpl.java:2780)
17-10-2004 20:58:44 DEBUG - Scheduling collection removes/(re)creates/updates (SessionImpl.java:2794)
17-10-2004 20:58:44 DEBUG - Flushed: 0 insertions, 1 updates, 0 deletions to 1 objects (SessionImpl.java:2270)
17-10-2004 20:58:44 DEBUG - Flushed: 0 (re)creations, 1 updates, 0 removals to 1 collections (SessionImpl.java:2275)
17-10-2004 20:58:44 DEBUG - listing entities: (Printer.java:75)
17-10-2004 20:58:44 DEBUG - Parent{hibernateId=7, children=[], pk=1, version=0} (Printer.java:82)
17-10-2004 20:58:44 DEBUG - executing flush (SessionImpl.java:2359)
17-10-2004 20:58:44 DEBUG - Updating entity: [Parent#7] (EntityPersister.java:648)
17-10-2004 20:58:44 DEBUG - Existing version: 0 -> New version: 1 (EntityPersister.java:649)
17-10-2004 20:58:44 DEBUG - about to open: 0 open PreparedStatements, 0 open ResultSets (BatcherImpl.java:200)
17-10-2004 20:58:44 DEBUG - update PARENT set VERSION=?, PK=? where HIBERNATE_ID=? and VERSION=? (BatcherImpl.java:226)
17-10-2004 20:58:44 DEBUG - preparing statement (BatcherImpl.java:249)
17-10-2004 20:58:44 DEBUG - Dehydrating entity: [Parent#7] (EntityPersister.java:388)
17-10-2004 20:58:44 DEBUG - done closing: 0 open PreparedStatements, 0 open ResultSets (BatcherImpl.java:207)
17-10-2004 20:58:44 DEBUG - closing statement (BatcherImpl.java:269)
17-10-2004 20:58:44 DEBUG - post flush (SessionImpl.java:2824)
17-10-2004 20:58:44 DEBUG - transaction completion (SessionImpl.java:585)
17-10-2004 20:58:44 DEBUG - closing session (SessionImpl.java:573)
17-10-2004 20:58:44 DEBUG - disconnecting session (SessionImpl.java:3336)
17-10-2004 20:58:44 DEBUG - returning connection to pool, pool size: 1 (DriverManagerConnectionProvider.java:120)
17-10-2004 20:58:44 DEBUG - transaction completion (SessionImpl.java:585)
17-10-2004 20:58:44 DEBUG - opened session (SessionImpl.java:555)
17-10-2004 20:58:44 DEBUG - flushing session (SessionImpl.java:2246)
17-10-2004 20:58:44 DEBUG - Flushing entities and processing referenced collections (SessionImpl.java:2439)
17-10-2004 20:58:44 DEBUG - Processing unreferenced collections (SessionImpl.java:2780)
17-10-2004 20:58:44 DEBUG - Scheduling collection removes/(re)creates/updates (SessionImpl.java:2794)
17-10-2004 20:58:44 DEBUG - Flushed: 0 insertions, 0 updates, 0 deletions to 0 objects (SessionImpl.java:2270)
17-10-2004 20:58:44 DEBUG - Flushed: 0 (re)creations, 0 updates, 0 removals to 0 collections (SessionImpl.java:2275)
17-10-2004 20:58:44 DEBUG - Dont need to execute flush (SessionImpl.java:1818)
17-10-2004 20:58:44 DEBUG - about to open: 0 open PreparedStatements, 0 open ResultSets (BatcherImpl.java:200)
17-10-2004 20:58:44 DEBUG - total checked-out connections: 0 (DriverManagerConnectionProvider.java:84)
17-10-2004 20:58:44 DEBUG - using pooled JDBC connection, pool size: 0 (DriverManagerConnectionProvider.java:90)
17-10-2004 20:58:44 DEBUG - select this.HIBERNATE_ID as HIBERNAT1_1_, this.VERSION as VERSION1_, this.PK as PK1_, this.PARENT_ID as PARENT_ID1_, parent1_.HIBERNATE_ID as HIBERNAT1_0_, parent1_.VERSION as VERSION0_, parent1_.PK as PK0_ from CHILD this left outer join PARENT parent1_ on this.PARENT_ID=parent1_.HIBERNATE_ID where this.PK=? (BatcherImpl.java:226)
17-10-2004 20:58:44 DEBUG - preparing statement (BatcherImpl.java:249)
17-10-2004 20:58:44 DEBUG - processing result set (Loader.java:277)
17-10-2004 20:58:44 DEBUG - result row: 7, 7 (Loader.java:480)
17-10-2004 20:58:44 DEBUG - Initializing object from ResultSet: 7 (Loader.java:611)
17-10-2004 20:58:44 DEBUG - Hydrating entity: Parent#7 (Loader.java:680)
17-10-2004 20:58:44 DEBUG - Version: 1 (SessionImpl.java:1910)
17-10-2004 20:58:44 DEBUG - Initializing object from ResultSet: 7 (Loader.java:611)
17-10-2004 20:58:44 DEBUG - Hydrating entity: Child#7 (Loader.java:680)
17-10-2004 20:58:44 DEBUG - Version: 0 (SessionImpl.java:1910)
17-10-2004 20:58:44 DEBUG - done processing result set (1 rows) (Loader.java:294)
17-10-2004 20:58:44 DEBUG - done closing: 0 open PreparedStatements, 0 open ResultSets (BatcherImpl.java:207)
17-10-2004 20:58:44 DEBUG - closing statement (BatcherImpl.java:269)
17-10-2004 20:58:44 DEBUG - total objects hydrated: 2 (Loader.java:314)
17-10-2004 20:58:44 DEBUG - resolving associations for [Parent#7] (SessionImpl.java:2202)
17-10-2004 20:58:44 DEBUG - creating collection wrapper:[Parent.children#7] (SessionImpl.java:3933)
17-10-2004 20:58:44 DEBUG - done materializing entity [Parent#7] (SessionImpl.java:2226)
17-10-2004 20:58:44 DEBUG - resolving associations for [Child#7] (SessionImpl.java:2202)
17-10-2004 20:58:44 DEBUG - loading [Parent#7] (SessionImpl.java:1986)
17-10-2004 20:58:44 DEBUG - attempting to resolve [Parent#7] (SessionImpl.java:2083)
17-10-2004 20:58:44 DEBUG - resolved object in session cache [Parent#7] (SessionImpl.java:2099)
17-10-2004 20:58:44 DEBUG - done materializing entity [Child#7] (SessionImpl.java:2226)
17-10-2004 20:58:44 DEBUG - initializing non-lazy collections (SessionImpl.java:3116)
17-10-2004 20:58:44 DEBUG - initializing collection [Parent.children#7] (SessionImpl.java:3260)
17-10-2004 20:58:44 DEBUG - checking second-level cache (SessionImpl.java:3261)
17-10-2004 20:58:44 DEBUG - collection not cached (SessionImpl.java:3267)
17-10-2004 20:58:44 DEBUG - about to open: 0 open PreparedStatements, 0 open ResultSets (BatcherImpl.java:200)
17-10-2004 20:58:44 DEBUG - select children0_.PARENT_ID as PARENT_ID__, children0_.HIBERNATE_ID as HIBERNAT1___, children0_.HIBERNATE_ID as HIBERNAT1_0_, children0_.VERSION as VERSION0_, children0_.PK as PK0_, children0_.PARENT_ID as PARENT_ID0_ from CHILD children0_ where children0_.PARENT_ID=? (BatcherImpl.java:226)
17-10-2004 20:58:44 DEBUG - preparing statement (BatcherImpl.java:249)
17-10-2004 20:58:44 DEBUG - result set contains (possibly empty) collection: [Parent.children#7] (Loader.java:402)
17-10-2004 20:58:44 DEBUG - uninitialized collection: initializing (SessionImpl.java:3018)
17-10-2004 20:58:44 DEBUG - processing result set (Loader.java:277)
17-10-2004 20:58:44 DEBUG - result row: 7 (Loader.java:480)
17-10-2004 20:58:44 DEBUG - found row of collection: [Parent.children#7] (Loader.java:367)
17-10-2004 20:58:44 DEBUG - reading row (SessionImpl.java:3041)
17-10-2004 20:58:44 DEBUG - loading [Child#7] (SessionImpl.java:1986)
17-10-2004 20:58:44 DEBUG - attempting to resolve [Child#7] (SessionImpl.java:2083)
17-10-2004 20:58:44 DEBUG - resolved object in session cache [Child#7] (SessionImpl.java:2099)
17-10-2004 20:58:44 DEBUG - done processing result set (1 rows) (Loader.java:294)
17-10-2004 20:58:44 DEBUG - done closing: 0 open PreparedStatements, 0 open ResultSets (BatcherImpl.java:207)
17-10-2004 20:58:44 DEBUG - closing statement (BatcherImpl.java:269)
17-10-2004 20:58:44 DEBUG - total objects hydrated: 0 (Loader.java:314)
17-10-2004 20:58:44 DEBUG - 1 collections were found in result set (SessionImpl.java:3077)
17-10-2004 20:58:44 DEBUG - collection fully initialized: [Parent.children#7] (SessionImpl.java:3095)
17-10-2004 20:58:44 DEBUG - 1 collections initialized (SessionImpl.java:3098)
17-10-2004 20:58:44 DEBUG - collection initialized (SessionImpl.java:3269)
17-10-2004 20:58:44 DEBUG - closing session (SessionImpl.java:573)
17-10-2004 20:58:44 DEBUG - disconnecting session (SessionImpl.java:3336)
17-10-2004 20:58:44 DEBUG - returning connection to pool, pool size: 1 (DriverManagerConnectionProvider.java:120)
17-10-2004 20:58:44 DEBUG - transaction completion (SessionImpl.java:585)
17-10-2004 20:58:44 DEBUG - opened session (SessionImpl.java:555)
17-10-2004 20:58:44 DEBUG - flushing session (SessionImpl.java:2246)
17-10-2004 20:58:44 DEBUG - Flushing entities and processing referenced collections (SessionImpl.java:2439)
17-10-2004 20:58:44 DEBUG - Processing unreferenced collections (SessionImpl.java:2780)
17-10-2004 20:58:45 DEBUG - Scheduling collection removes/(re)creates/updates (SessionImpl.java:2794)
17-10-2004 20:58:45 DEBUG - Flushed: 0 insertions, 0 updates, 0 deletions to 0 objects (SessionImpl.java:2270)
17-10-2004 20:58:45 DEBUG - running Session.finalize() (SessionImpl.java:3388)
17-10-2004 20:58:45 DEBUG - Flushed: 0 (re)creations, 0 updates, 0 removals to 0 collections (SessionImpl.java:2275)
17-10-2004 20:58:45 DEBUG - Dont need to execute flush (SessionImpl.java:1818)
17-10-2004 20:58:45 DEBUG - about to open: 0 open PreparedStatements, 0 open ResultSets (BatcherImpl.java:200)
17-10-2004 20:58:45 DEBUG - total checked-out connections: 0 (DriverManagerConnectionProvider.java:84)
17-10-2004 20:58:45 DEBUG - using pooled JDBC connection, pool size: 0 (DriverManagerConnectionProvider.java:90)
17-10-2004 20:58:45 DEBUG - select this.HIBERNATE_ID as HIBERNAT1_0_, this.VERSION as VERSION0_, this.PK as PK0_ from PARENT this where this.PK=? (BatcherImpl.java:226)
17-10-2004 20:58:45 DEBUG - preparing statement (BatcherImpl.java:249)
17-10-2004 20:58:45 DEBUG - processing result set (Loader.java:277)
17-10-2004 20:58:45 DEBUG - result row: 7 (Loader.java:480)
17-10-2004 20:58:45 DEBUG - Initializing object from ResultSet: 7 (Loader.java:611)
17-10-2004 20:58:45 DEBUG - Hydrating entity: Parent#7 (Loader.java:680)
17-10-2004 20:58:45 DEBUG - Version: 1 (SessionImpl.java:1910)
17-10-2004 20:58:45 DEBUG - done processing result set (1 rows) (Loader.java:294)
17-10-2004 20:58:45 DEBUG - done closing: 0 open PreparedStatements, 0 open ResultSets (BatcherImpl.java:207)
17-10-2004 20:58:45 DEBUG - closing statement (BatcherImpl.java:269)
17-10-2004 20:58:45 DEBUG - total objects hydrated: 1 (Loader.java:314)
17-10-2004 20:58:45 DEBUG - resolving associations for [Parent#7] (SessionImpl.java:2202)
17-10-2004 20:58:45 DEBUG - creating collection wrapper:[Parent.children#7] (SessionImpl.java:3933)
17-10-2004 20:58:45 DEBUG - done materializing entity [Parent#7] (SessionImpl.java:2226)
17-10-2004 20:58:45 DEBUG - initializing non-lazy collections (SessionImpl.java:3116)
17-10-2004 20:58:45 DEBUG - initializing collection [Parent.children#7] (SessionImpl.java:3260)
17-10-2004 20:58:45 DEBUG - checking second-level cache (SessionImpl.java:3261)
17-10-2004 20:58:45 DEBUG - collection not cached (SessionImpl.java:3267)
17-10-2004 20:58:45 DEBUG - about to open: 0 open PreparedStatements, 0 open ResultSets (BatcherImpl.java:200)
17-10-2004 20:58:45 DEBUG - select children0_.PARENT_ID as PARENT_ID__, children0_.HIBERNATE_ID as HIBERNAT1___, children0_.HIBERNATE_ID as HIBERNAT1_0_, children0_.VERSION as VERSION0_, children0_.PK as PK0_, children0_.PARENT_ID as PARENT_ID0_ from CHILD children0_ where children0_.PARENT_ID=? (BatcherImpl.java:226)
17-10-2004 20:58:45 DEBUG - preparing statement (BatcherImpl.java:249)
17-10-2004 20:58:45 DEBUG - result set contains (possibly empty) collection: [Parent.children#7] (Loader.java:402)
17-10-2004 20:58:45 DEBUG - uninitialized collection: initializing (SessionImpl.java:3018)
17-10-2004 20:58:45 DEBUG - processing result set (Loader.java:277)
17-10-2004 20:58:45 DEBUG - result row: 7 (Loader.java:480)
17-10-2004 20:58:45 DEBUG - Initializing object from ResultSet: 7 (Loader.java:611)
17-10-2004 20:58:45 DEBUG - Hydrating entity: Child#7 (Loader.java:680)
17-10-2004 20:58:45 DEBUG - Version: 0 (SessionImpl.java:1910)
17-10-2004 20:58:45 DEBUG - found row of collection: [Parent.children#7] (Loader.java:367)
17-10-2004 20:58:45 DEBUG - reading row (SessionImpl.java:3041)
17-10-2004 20:58:45 DEBUG - loading [Child#7] (SessionImpl.java:1986)
17-10-2004 20:58:45 DEBUG - attempting to resolve [Child#7] (SessionImpl.java:2083)
17-10-2004 20:58:45 DEBUG - resolved object in session cache [Child#7] (SessionImpl.java:2099)
17-10-2004 20:58:45 DEBUG - done processing result set (1 rows) (Loader.java:294)
17-10-2004 20:58:45 DEBUG - done closing: 0 open PreparedStatements, 0 open ResultSets (BatcherImpl.java:207)
17-10-2004 20:58:45 DEBUG - closing statement (BatcherImpl.java:269)
17-10-2004 20:58:45 DEBUG - total objects hydrated: 1 (Loader.java:314)
17-10-2004 20:58:45 DEBUG - resolving associations for [Child#7] (SessionImpl.java:2202)
17-10-2004 20:58:45 DEBUG - loading [Parent#7] (SessionImpl.java:1986)
17-10-2004 20:58:45 DEBUG - attempting to resolve [Parent#7] (SessionImpl.java:2083)
17-10-2004 20:58:45 DEBUG - resolved object in session cache [Parent#7] (SessionImpl.java:2099)
17-10-2004 20:58:45 DEBUG - done materializing entity [Child#7] (SessionImpl.java:2226)
17-10-2004 20:58:45 DEBUG - 1 collections were found in result set (SessionImpl.java:3077)
17-10-2004 20:58:45 DEBUG - collection fully initialized: [Parent.children#7] (SessionImpl.java:3095)
17-10-2004 20:58:45 DEBUG - 1 collections initialized (SessionImpl.java:3098)
17-10-2004 20:58:45 DEBUG - collection initialized (SessionImpl.java:3269)
17-10-2004 20:58:45 DEBUG - closing session (SessionImpl.java:573)
17-10-2004 20:58:45 DEBUG - disconnecting session (SessionImpl.java:3336)
17-10-2004 20:58:45 DEBUG - returning connection to pool, pool size: 1 (DriverManagerConnectionProvider.java:120)
17-10-2004 20:58:45 DEBUG - transaction completion (SessionImpl.java:585)
17-10-2004 20:58:45 DEBUG - opened session (SessionImpl.java:555)
17-10-2004 20:58:45 DEBUG - begin (JDBCTransaction.java:37)
17-10-2004 20:58:45 DEBUG - total checked-out connections: 0 (DriverManagerConnectionProvider.java:84)
17-10-2004 20:58:45 DEBUG - using pooled JDBC connection, pool size: 0 (DriverManagerConnectionProvider.java:90)
17-10-2004 20:58:45 DEBUG - current autocommit status:false (JDBCTransaction.java:41)
17-10-2004 20:58:45 DEBUG - deleting a transient instance (SessionImpl.java:1132)
17-10-2004 20:58:45 DEBUG - deleting [Parent#7] (SessionImpl.java:1179)
17-10-2004 20:58:45 DEBUG - processing cascades for: Parent (Cascades.java:497)
17-10-2004 20:58:45 DEBUG - cascading to collection: Parent.children (Cascades.java:524)
17-10-2004 20:58:45 DEBUG - cascading to delete() (Cascades.java:60)
17-10-2004 20:58:45 DEBUG - version unsaved-value strategy UNDEFINED (Cascades.java:396)
17-10-2004 20:58:45 DEBUG - running Session.finalize() (SessionImpl.java:3388)
17-10-2004 20:58:45 DEBUG - id unsaved-value strategy NULL (Cascades.java:341)
17-10-2004 20:58:45 DEBUG - deleting a transient instance (SessionImpl.java:1132)
17-10-2004 20:58:45 DEBUG - deleting [Child#7] (SessionImpl.java:1179)
17-10-2004 20:58:45 DEBUG - done processing cascades for: Parent (Cascades.java:506)
17-10-2004 20:58:45 DEBUG - processing cascades for: Parent (Cascades.java:497)
17-10-2004 20:58:45 DEBUG - done processing cascades for: Parent (Cascades.java:506)
17-10-2004 20:58:45 DEBUG - commit (JDBCTransaction.java:59)
17-10-2004 20:58:45 DEBUG - flushing session (SessionImpl.java:2246)
17-10-2004 20:58:45 DEBUG - Flushing entities and processing referenced collections (SessionImpl.java:2439)
17-10-2004 20:58:45 DEBUG - Processing unreferenced collections (SessionImpl.java:2780)
17-10-2004 20:58:45 DEBUG - Collection dereferenced: [Parent.children#7] (SessionImpl.java:2901)
17-10-2004 20:58:45 DEBUG - Scheduling collection removes/(re)creates/updates (SessionImpl.java:2794)
17-10-2004 20:58:45 DEBUG - Flushed: 0 insertions, 0 updates, 2 deletions to 2 objects (SessionImpl.java:2270)
17-10-2004 20:58:45 DEBUG - Flushed: 0 (re)creations, 0 updates, 1 removals to 1 collections (SessionImpl.java:2275)
17-10-2004 20:58:45 DEBUG - listing entities: (Printer.java:75)
17-10-2004 20:58:45 DEBUG - Child{hibernateId=7, parent=Parent#7, pk=1, version=0} (Printer.java:82)
17-10-2004 20:58:45 DEBUG - Parent{hibernateId=7, children=[Child#7], pk=1, version=1} (Printer.java:82)
17-10-2004 20:58:45 DEBUG - executing flush (SessionImpl.java:2359)
17-10-2004 20:58:45 DEBUG - Deleting entity: [Child#7] (EntityPersister.java:570)
17-10-2004 20:58:45 DEBUG - Version: 0 (EntityPersister.java:571)
17-10-2004 20:58:45 DEBUG - about to open: 0 open PreparedStatements, 0 open ResultSets (BatcherImpl.java:200)
17-10-2004 20:58:45 DEBUG - delete from CHILD where HIBERNATE_ID=? and VERSION=? (BatcherImpl.java:226)
17-10-2004 20:58:45 DEBUG - preparing statement (BatcherImpl.java:249)
17-10-2004 20:58:45 DEBUG - done closing: 0 open PreparedStatements, 0 open ResultSets (BatcherImpl.java:207)
17-10-2004 20:58:45 DEBUG - closing statement (BatcherImpl.java:269)
17-10-2004 20:58:45 DEBUG - Deleting entity: [Parent#7] (EntityPersister.java:570)
17-10-2004 20:58:45 DEBUG - Version: 1 (EntityPersister.java:571)
17-10-2004 20:58:45 DEBUG - about to open: 0 open PreparedStatements, 0 open ResultSets (BatcherImpl.java:200)
17-10-2004 20:58:45 DEBUG - delete from PARENT where HIBERNATE_ID=? and VERSION=? (BatcherImpl.java:226)
17-10-2004 20:58:45 DEBUG - preparing statement (BatcherImpl.java:249)
17-10-2004 20:58:45 DEBUG - done closing: 0 open PreparedStatements, 0 open ResultSets (BatcherImpl.java:207)
17-10-2004 20:58:45 DEBUG - closing statement (BatcherImpl.java:269)
17-10-2004 20:58:45 DEBUG - post flush (SessionImpl.java:2824)
17-10-2004 20:58:45 DEBUG - transaction completion (SessionImpl.java:585)
17-10-2004 20:58:45 DEBUG - closing session (SessionImpl.java:573)
17-10-2004 20:58:45 DEBUG - disconnecting session (SessionImpl.java:3336)
17-10-2004 20:58:45 DEBUG - returning connection to pool, pool size: 1 (DriverManagerConnectionProvider.java:120)
17-10-2004 20:58:45 DEBUG - transaction completion (SessionImpl.java:585)
17-10-2004 20:58:45 DEBUG - running Session.finalize() (SessionImpl.java:3388)