Hibernate Community • View topic - Problem with subclasses and detached entities

View unanswered posts | View active topics

Board index » Hibernate & Java Persistence » Hibernate Users

All times are UTC - 5 hours [ DST ]

Problem with subclasses and detached entities

Page 1 of 1

[ 2 posts ]

Previous topic | Next topic

Author

Message

DWright

Post subject: Problem with subclasses and detached entities

Posted: Fri Sep 03, 2004 7:04 pm

Regular

Joined: Wed Jul 07, 2004 2:00 pm
Posts: 64

select-before-update does not appear to work when using inheritence (table-per-heirarchy style) with detach/attach operations. The sample application below (a vital person-pet tracking app) will properly handle the save-before-update on the (root) person object, but the cat and dog collections will be updated. I know that the use of inheritence is odd, considering that this sample explicitly separates the cat and dog collections, but the real application has a reason for using this style.

Note from the debug output that the update (SQL) statements also indicate that all columns are being updated, even though dynamic-update is true. Even though I am using detach/attach, I was under the impression that dynamic-update should work if you use select-before-update.

So, those are my problems:
unexplained updates when data hasn't changed, and updates that include all columns.

These will cause problems with our triggers.

Ideas?

Hibernate version: 2.1.6

Mapping documents:

Code:

<?xml version="1.0" encoding="UTF-8"?>
<!DOCTYPE hibernate-mapping SYSTEM "file:///c:/testdtds/hibernate-mapping-2.0.dtd">
<hibernate-mapping package="model">
   <class name="Person" select-before-update="true" table="person" dynamic-update="true">
      <id access="field" column="id" name="id" type="integer">
         <generator class="identity"/>
      </id>
      <version name="version" access="field" column="version" type="integer"/>
      <property name="name" access="field" column="name" length="60" not-null="true" type="string"/>
      <set name="cats" access="field" cascade="all-delete-orphan" inverse="true" where="type='0001'">
         <key column="owner"/>
         <one-to-many class="Pet"/>
      </set>
      <set name="dogs" access="field" cascade="all-delete-orphan" inverse="true" where="type='0002'">
         <key column="owner"/>
         <one-to-many class="Pet"/>
      </set>
   </class>
</hibernate-mapping>

<?xml version="1.0" encoding="UTF-8"?>
<!DOCTYPE hibernate-mapping SYSTEM "file:///c:/testdtds/hibernate-mapping-2.0.dtd">
<hibernate-mapping package="model">
   <class name="Pet" select-before-update="true" table="pet" dynamic-update="true">
      <id access="field" column="id" name="id" type="integer">
         <generator class="identity"/>
      </id>
      <discriminator column="type" length="4" type="string"/>
      <version name="version" access="field" column="version" type="integer"/>
      <many-to-one name="owner" access="field" class="Person" column="owner" not-null="true"/>
      <property name="name" access="field" column="name" length="30" not-null="true" type="string"/>
      <subclass name="Cat" discriminator-value="0001" extends="Pet" dynamic-update="true">
         <property name="catFld" access="field" column="cat_fld" length="6" type="string"/>
      </subclass>
      <subclass name="Dog" discriminator-value="0002" extends="Pet" dynamic-update="true">
         <property name="dogFld" access="field" column="dog_fld" length="6" type="string"/>
      </subclass>
   </class>
</hibernate-mapping>

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

Code:

Test.java:

import model.Person;
import net.sf.hibernate.HibernateException;
import net.sf.hibernate.Session;
import net.sf.hibernate.SessionFactory;
import net.sf.hibernate.Transaction;
import net.sf.hibernate.cfg.Configuration;

public class Test {
   private static SessionFactory factory;

   public static void main(String[] args) throws HibernateException {
      Configuration config = new Configuration();
      config.configure();
      factory = config.buildSessionFactory();
      Person p = getOwnerZoo();
      System.out.println("!!!Got person " + p);
      saveOwnerZoo(p);
   }

   private static void saveOwnerZoo(Person p) throws HibernateException {
      Session session = factory.openSession();
      Transaction tx = session.beginTransaction();
      session.saveOrUpdate(p);
      tx.commit();
      session.close();
   }

   private static Person getOwnerZoo() throws HibernateException {
      Session session = factory.openSession();
      Transaction tx = session.beginTransaction();
      Person p = (Person)session.load(Person.class, new Integer(1));
      tx.commit();
      session.close();
      return p;
   }
}

Person.java:
package model;

import java.util.HashSet;
import java.util.Iterator;
import java.util.Set;

public class Person {
   private Integer id;
   private Integer version;
   private String name;
   private Set cats;
   private Set dogs;

   public Person() {
      cats = new HashSet();
      dogs = new HashSet();
   }
   public boolean equals(Object obj) {
      if (obj == null || !obj.getClass().equals(getClass())) {
         return false;
      }
      Person p2 = (Person)obj;
      return p2.id.equals(id);
   }
   public int hashCode() {
      return id.hashCode();
   }
   public String toString() {
      StringBuffer buf = new StringBuffer("Person[id=");
      buf.append(id);
      buf.append(", version=");
      buf.append(version);
      buf.append(", name='");
      buf.append(name);
      buf.append("', cats={");
      Iterator it = cats.iterator();
      while (it.hasNext()) {
         Pet p = (Pet)it.next();
         buf.append(p);
         if (it.hasNext()) {
            buf.append(",");
         }
      }
      buf.append("}, dogs={");
      it = dogs.iterator();
      while (it.hasNext()) {
         Pet p = (Pet)it.next();
         buf.append(p);
         if (it.hasNext()) {
            buf.append(",");
         }
      }
      buf.append("}]");
      return buf.toString();
   }
}

Pet.java:
package model;

public abstract class Pet {
   private Integer id;
   private Integer version;
   private String name;
   private Person owner;

   public Pet() {
   }
   public boolean equals(Object obj) {
      if (obj == null || !obj.getClass().equals(getClass())) {
         return false;
      }
      Pet p2 = (Pet)obj;
      return p2.name.equals(name);
   }
   public int hashCode() {
      return name.hashCode();
   }
   public String toString() {
      return "Pet[id=" + id + ", version=" + version + ", name='" + name
            + "']";
   }
}

Cat.java:
package model;

public class Cat extends Pet {
   private String catFld;

   public Cat() {
   }
   public String toString() {
      StringBuffer buf = new StringBuffer("Cat[");
      buf.append(super.toString());
      buf.append(", catFld='");
      buf.append(catFld);
      buf.append("']");
      return buf.toString();
   }
}

Dog.java:
package model;

public class Dog extends Pet {
   private String dogFld;

   public Dog() {
   }
   public String toString() {
      StringBuffer buf = new StringBuffer("Dog[");
      buf.append(super.toString());
      buf.append(", dogFld='");
      buf.append(dogFld);
      buf.append("']");
      return buf.toString();
   }
}

Full stack trace of any exception that occurs:

Name and version of the database you are using:
MySQL, version 4.0.16
The same problem also appears with Oracle 9.something.

Debug level Hibernate log excerpt:

Code:

49:45,290  INFO Environment:469 - Hibernate 2.1.6
49:45,300  INFO Environment:498 - hibernate.properties not found
49:45,300  INFO Environment:529 - using CGLIB reflection optimizer
49:45,310  INFO Configuration:895 - configuring from resource: /hibernate.cfg.xml
49:45,310  INFO Configuration:867 - Configuration resource: /hibernate.cfg.xml
49:45,440 DEBUG Configuration:853 - hibernate.connection.url=jdbc:mysql://localhost/test
49:45,440 DEBUG Configuration:853 - hibernate.show_sql=true
49:45,440 DEBUG Configuration:853 - hibernate.dialect=net.sf.hibernate.dialect.MySQLDialect
49:45,440 DEBUG Configuration:853 - hibernate.connection.driver_class=com.mysql.jdbc.Driver
49:45,440 DEBUG Configuration:853 - hibernate.connection.username=david
49:45,440 DEBUG Configuration:853 - hibernate.connection.password=password
49:45,450 DEBUG Configuration:1012 - null<-org.dom4j.tree.DefaultAttribute@1ac2f9c [Attribute: name resource value "model/Person.hbm.xml"]
49:45,450  INFO Configuration:331 - Mapping resource: model/Person.hbm.xml
49:45,550  INFO Binder:229 - Mapping class: model.Person -> person
49:45,620 DEBUG Binder:486 - Mapped property: id -> id, type: integer
49:45,620 DEBUG Binder:486 - Mapped property: version -> version, type: integer
49:45,640 DEBUG Binder:486 - Mapped property: name -> name, type: string
49:45,660 DEBUG Binder:486 - Mapped property: cats, type: java.util.Set
49:45,660 DEBUG Binder:486 - Mapped property: dogs, type: java.util.Set
49:45,660 DEBUG Configuration:1012 - null<-org.dom4j.tree.DefaultAttribute@1e152c5 [Attribute: name resource value "model/Pet.hbm.xml"]
49:45,670  INFO Configuration:331 - Mapping resource: model/Pet.hbm.xml
49:45,701  INFO Binder:229 - Mapping class: model.Pet -> pet
49:45,701 DEBUG Binder:486 - Mapped property: id -> id, type: integer
49:45,701 DEBUG Binder:486 - Mapped property: version -> version, type: integer
49:45,701 DEBUG Binder:486 - Mapped property: owner -> owner, type: model.Person
49:45,701 DEBUG Binder:486 - Mapped property: name -> name, type: string
49:45,741  INFO Binder:169 - Mapping subclass: model.Cat -> pet
49:45,741 DEBUG Binder:486 - Mapped property: catFld -> cat_fld, type: string
49:45,761  INFO Binder:169 - Mapping subclass: model.Dog -> pet
49:45,761 DEBUG Binder:486 - Mapped property: dogFld -> dog_fld, type: string
49:45,761  INFO Configuration:1053 - Configured SessionFactory: null
49:45,761 DEBUG Configuration:1054 - properties: {hibernate.connection.password=password, java.runtime.name=Java(TM) 2 Runtime Environment, Standard Edition, sun.boot.library.path=C:\j2sdk1.4.2_04\jre\bin, java.vm.version=1.4.2_04-b05, hibernate.connection.username=david, 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, user.country=CA, sun.os.patch.level=Service Pack 1, java.vm.specification.name=Java Virtual Machine Specification, user.dir=C:\eclipse\workspace\Hibtest, java.runtime.version=1.4.2_04-b05, java.awt.graphicsenv=sun.awt.Win32GraphicsEnvironment, java.endorsed.dirs=C:\j2sdk1.4.2_04\jre\lib\endorsed, os.arch=x86, java.io.tmpdir=C:\DOCUME~1\WRIGHT~1\LOCALS~1\Temp\, line.separator=
, java.vm.specification.vendor=Sun Microsystems Inc., user.variant=, os.name=Windows XP, sun.java2d.fontpath=, java.library.path=C:\j2sdk1.4.2_04\bin;.;C:\WINDOWS\System32;C:\WINDOWS;C:\oracle\ora8i\bin;C:\Program Files\Oracle\jre\1.1.7\bin;C:\WINDOWS\system32;C:\WINDOWS;C:\WINDOWS\System32\Wbem;C:\oracle\ora92\bin;C:\Program Files\Oracle\jre\1.1.8\bin;C:\oracle\Ora92\Olap\XSA632;C:\Program Files\Rational\common;C:\Program Files\Rational\ClearCase\bin;c:\j2sdk1.4.2_04\bin;C:\jakarta-tomcat-5.0.27\bin, java.specification.name=Java Platform API Specification, java.class.version=48.0, java.util.prefs.PreferencesFactory=java.util.prefs.WindowsPreferencesFactory, os.version=5.1, user.home=C:\Documents and Settings\WrightDAVI, user.timezone=America/New_York, java.awt.printerjob=sun.awt.windows.WPrinterJob, file.encoding=Cp1252, java.specification.version=1.4, hibernate.connection.driver_class=com.mysql.jdbc.Driver, user.name=wrightdavi, java.class.path=C:\eclipse\workspace\Hibtest\bin;C:\hibernate-2.1\hibernate2.jar;C:\hibernate-2.1\lib\jta.jar;C:\hibernate-2.1\lib\log4j-1.2.8.jar;C:\hibernate-2.1\lib\odmg-3.0.jar;C:\hibernate-2.1\lib\cglib-full-2.0.2.jar;C:\hibernate-2.1\lib\commons-collections-2.1.1.jar;C:\hibernate-2.1\lib\commons-dbcp-1.2.1.jar;C:\hibernate-2.1\lib\commons-logging-1.0.4.jar;C:\hibernate-2.1\lib\commons-pool-1.2.jar;C:\hibernate-2.1\lib\dom4j-1.4.jar;C:\hibernate-2.1\lib\ehcache-0.9.jar;C:\hibernate-2.1\lib\jdbc2_0-stdext.jar;C:\mysql-connector-java-3.0.9-stable\mysql-connector-java-3.0.9-stable\mysql-connector-java-3.0.9-stable-bin.jar, hibernate.show_sql=true, java.vm.specification.version=1.0, java.home=C:\j2sdk1.4.2_04\jre, sun.arch.data.model=32, hibernate.dialect=net.sf.hibernate.dialect.MySQLDialect, hibernate.connection.url=jdbc:mysql://localhost/test, 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_04, java.ext.dirs=C:\j2sdk1.4.2_04\jre\lib\ext, sun.boot.class.path=C:\j2sdk1.4.2_04\jre\lib\rt.jar;C:\j2sdk1.4.2_04\jre\lib\i18n.jar;C:\j2sdk1.4.2_04\jre\lib\sunrsasign.jar;C:\j2sdk1.4.2_04\jre\lib\jsse.jar;C:\j2sdk1.4.2_04\jre\lib\jce.jar;C:\j2sdk1.4.2_04\jre\lib\charsets.jar;C:\j2sdk1.4.2_04\jre\classes, java.vendor=Sun Microsystems Inc., file.separator=\, java.vendor.url.bug=http://java.sun.com/cgi-bin/bugreport.cgi, sun.io.unicode.encoding=UnicodeLittle, sun.cpu.endian=little, sun.cpu.isalist=pentium i486 i386}
49:45,761  INFO Configuration:627 - processing one-to-many association mappings
49:45,761 DEBUG Binder:1353 - Second pass for collection: model.Person.cats
49:45,761  INFO Binder:1181 - Mapping collection: model.Person.cats -> pet
49:45,761 DEBUG Binder:1368 - Mapped collection key: owner, one-to-many: model.Pet
49:45,761 DEBUG Binder:1353 - Second pass for collection: model.Person.dogs
49:45,761  INFO Binder:1181 - Mapping collection: model.Person.dogs -> pet
49:45,761 DEBUG Binder:1368 - Mapped collection key: owner, one-to-many: model.Pet
49:45,771  INFO Configuration:636 - processing one-to-one association property references
49:45,771  INFO Configuration:661 - processing foreign key constraints
49:45,771 DEBUG Configuration:678 - resolving reference to class: model.Person
49:45,791  INFO Dialect:82 - Using dialect: net.sf.hibernate.dialect.MySQLDialect
49:45,791  INFO SettingsFactory:59 - Maximim outer join fetch depth: 2
49:45,791  INFO SettingsFactory:63 - Use outer join fetching: true
49:45,801  INFO DriverManagerConnectionProvider:42 - Using Hibernate built-in connection pool (not for production use!)
49:45,801  INFO DriverManagerConnectionProvider:43 - Hibernate connection pool size: 20
49:45,811  INFO DriverManagerConnectionProvider:77 - using driver: com.mysql.jdbc.Driver at URL: jdbc:mysql://localhost/test
49:45,811  INFO DriverManagerConnectionProvider:78 - connection properties: {user=david, password=password}
49:45,811  INFO TransactionManagerLookupFactory:33 - No TransactionManagerLookup configured (in JTA environment, use of process level read-write cache is not recommended)
49:45,821 DEBUG DriverManagerConnectionProvider:84 - total checked-out connections: 0
49:45,821 DEBUG DriverManagerConnectionProvider:100 - opening new JDBC connection
49:46,001 DEBUG DriverManagerConnectionProvider:106 - created connection to: jdbc:mysql://localhost/test, Isolation Level: 4
49:46,001 DEBUG DriverManagerConnectionProvider:120 - returning connection to pool, pool size: 1
49:46,001  INFO SettingsFactory:103 - Use scrollable result sets: true
49:46,001  INFO SettingsFactory:106 - Use JDBC3 getGeneratedKeys(): true
49:46,001  INFO SettingsFactory:109 - Optimize cache for minimal puts: false
49:46,001  INFO SettingsFactory:115 - echoing all SQL to stdout
49:46,001  INFO SettingsFactory:118 - Query language substitutions: {}
49:46,001  INFO SettingsFactory:129 - cache provider: net.sf.hibernate.cache.EhCacheProvider
49:46,011  INFO Configuration:1116 - instantiating and configuring caches
49:46,131  INFO SessionFactoryImpl:118 - building session factory
49:46,131 DEBUG SessionFactoryImpl:124 - instantiating session factory with properties: {hibernate.connection.password=password, java.runtime.name=Java(TM) 2 Runtime Environment, Standard Edition, sun.boot.library.path=C:\j2sdk1.4.2_04\jre\bin, java.vm.version=1.4.2_04-b05, hibernate.connection.username=david, 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, user.country=CA, sun.os.patch.level=Service Pack 1, java.vm.specification.name=Java Virtual Machine Specification, user.dir=C:\eclipse\workspace\Hibtest, java.runtime.version=1.4.2_04-b05, java.awt.graphicsenv=sun.awt.Win32GraphicsEnvironment, java.endorsed.dirs=C:\j2sdk1.4.2_04\jre\lib\endorsed, os.arch=x86, java.io.tmpdir=C:\DOCUME~1\WRIGHT~1\LOCALS~1\Temp\, line.separator=
, java.vm.specification.vendor=Sun Microsystems Inc., user.variant=, os.name=Windows XP, sun.java2d.fontpath=, java.library.path=C:\j2sdk1.4.2_04\bin;.;C:\WINDOWS\System32;C:\WINDOWS;C:\oracle\ora8i\bin;C:\Program Files\Oracle\jre\1.1.7\bin;C:\WINDOWS\system32;C:\WINDOWS;C:\WINDOWS\System32\Wbem;C:\oracle\ora92\bin;C:\Program Files\Oracle\jre\1.1.8\bin;C:\oracle\Ora92\Olap\XSA632;C:\Program Files\Rational\common;C:\Program Files\Rational\ClearCase\bin;c:\j2sdk1.4.2_04\bin;C:\jakarta-tomcat-5.0.27\bin, java.specification.name=Java Platform API Specification, java.class.version=48.0, java.util.prefs.PreferencesFactory=java.util.prefs.WindowsPreferencesFactory, os.version=5.1, user.home=C:\Documents and Settings\WrightDAVI, user.timezone=America/New_York, java.awt.printerjob=sun.awt.windows.WPrinterJob, file.encoding=Cp1252, java.specification.version=1.4, hibernate.connection.driver_class=com.mysql.jdbc.Driver, user.name=wrightdavi, java.class.path=C:\eclipse\workspace\Hibtest\bin;C:\hibernate-2.1\hibernate2.jar;C:\hibernate-2.1\lib\jta.jar;C:\hibernate-2.1\lib\log4j-1.2.8.jar;C:\hibernate-2.1\lib\odmg-3.0.jar;C:\hibernate-2.1\lib\cglib-full-2.0.2.jar;C:\hibernate-2.1\lib\commons-collections-2.1.1.jar;C:\hibernate-2.1\lib\commons-dbcp-1.2.1.jar;C:\hibernate-2.1\lib\commons-logging-1.0.4.jar;C:\hibernate-2.1\lib\commons-pool-1.2.jar;C:\hibernate-2.1\lib\dom4j-1.4.jar;C:\hibernate-2.1\lib\ehcache-0.9.jar;C:\hibernate-2.1\lib\jdbc2_0-stdext.jar;C:\mysql-connector-java-3.0.9-stable\mysql-connector-java-3.0.9-stable\mysql-connector-java-3.0.9-stable-bin.jar, hibernate.show_sql=true, java.vm.specification.version=1.0, java.home=C:\j2sdk1.4.2_04\jre, sun.arch.data.model=32, hibernate.dialect=net.sf.hibernate.dialect.MySQLDialect, hibernate.connection.url=jdbc:mysql://localhost/test, 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_04, java.ext.dirs=C:\j2sdk1.4.2_04\jre\lib\ext, sun.boot.class.path=C:\j2sdk1.4.2_04\jre\lib\rt.jar;C:\j2sdk1.4.2_04\jre\lib\i18n.jar;C:\j2sdk1.4.2_04\jre\lib\sunrsasign.jar;C:\j2sdk1.4.2_04\jre\lib\jsse.jar;C:\j2sdk1.4.2_04\jre\lib\jce.jar;C:\j2sdk1.4.2_04\jre\lib\charsets.jar;C:\j2sdk1.4.2_04\jre\classes, java.vendor=Sun Microsystems Inc., file.separator=\, java.vendor.url.bug=http://java.sun.com/cgi-bin/bugreport.cgi, sun.io.unicode.encoding=UnicodeLittle, sun.cpu.endian=little, sun.cpu.isalist=pentium i486 i386}
49:46,442 DEBUG SessionFactoryObjectFactory:39 - initializing class SessionFactoryObjectFactory
49:46,442 DEBUG SessionFactoryObjectFactory:76 - registered: 2c900038fec67d2f00fec67d30c00000 (unnamed)
49:46,442  INFO SessionFactoryObjectFactory:82 - Not binding factory to JNDI, no JNDI name configured
49:46,442 DEBUG SessionFactoryImpl:195 - instantiated session factory
49:46,502 DEBUG SessionImpl:555 - opened session
49:46,502 DEBUG JDBCTransaction:37 - begin
49:46,502 DEBUG DriverManagerConnectionProvider:84 - total checked-out connections: 0
49:46,502 DEBUG DriverManagerConnectionProvider:90 - using pooled JDBC connection, pool size: 0
49:46,502 DEBUG JDBCTransaction:41 - current autocommit status:false
49:46,502 DEBUG SessionImpl:1986 - loading [model.Person#1]
49:46,512 DEBUG SessionImpl:2083 - attempting to resolve [model.Person#1]
49:46,512 DEBUG SessionImpl:2116 - object not resolved in any cache [model.Person#1]
49:46,512 DEBUG EntityPersister:416 - Materializing entity: [model.Person#1]
49:46,512 DEBUG BatcherImpl:200 - about to open: 0 open PreparedStatements, 0 open ResultSets
49:46,522 DEBUG SQL:226 - select person0_.id as id0_, person0_.version as version0_, person0_.name as name0_ from person person0_ where person0_.id=?
Hibernate: select person0_.id as id0_, person0_.version as version0_, person0_.name as name0_ from person person0_ where person0_.id=?
49:46,522 DEBUG BatcherImpl:249 - preparing statement
49:46,532 DEBUG Loader:277 - processing result set
49:46,542 DEBUG Loader:480 - result row: 1
49:46,542 DEBUG Loader:611 - Initializing object from ResultSet: 1
49:46,542 DEBUG Loader:680 - Hydrating entity: model.Person#1
49:46,562 DEBUG SessionImpl:1910 - Version: 12
49:46,562 DEBUG Loader:294 - done processing result set (1 rows)
49:46,562 DEBUG BatcherImpl:207 - done closing: 0 open PreparedStatements, 0 open ResultSets
49:46,562 DEBUG BatcherImpl:269 - closing statement
49:46,562 DEBUG Loader:314 - total objects hydrated: 1
49:46,562 DEBUG SessionImpl:2202 - resolving associations for [model.Person#1]
49:46,562 DEBUG SessionImpl:3933 - creating collection wrapper:[model.Person.cats#1]
49:46,572 DEBUG SessionImpl:3933 - creating collection wrapper:[model.Person.dogs#1]
49:46,572 DEBUG SessionImpl:2226 - done materializing entity [model.Person#1]
49:46,572 DEBUG SessionImpl:3116 - initializing non-lazy collections
49:46,572 DEBUG SessionImpl:3260 - initializing collection [model.Person.dogs#1]
49:46,582 DEBUG SessionImpl:3261 - checking second-level cache
49:46,582 DEBUG SessionImpl:3267 - collection not cached
49:46,582 DEBUG BatcherImpl:200 - about to open: 0 open PreparedStatements, 0 open ResultSets
49:46,582 DEBUG SQL:226 - select dogs0_.owner as owner__, dogs0_.id as id__, dogs0_.id as id0_, dogs0_.type as type0_, dogs0_.version as version0_, dogs0_.owner as owner0_, dogs0_.name as name0_, dogs0_.cat_fld as cat_fld0_, dogs0_.dog_fld as dog_fld0_ from pet dogs0_ where dogs0_.owner=? and dogs0_.type='0002'
Hibernate: select dogs0_.owner as owner__, dogs0_.id as id__, dogs0_.id as id0_, dogs0_.type as type0_, dogs0_.version as version0_, dogs0_.owner as owner0_, dogs0_.name as name0_, dogs0_.cat_fld as cat_fld0_, dogs0_.dog_fld as dog_fld0_ from pet dogs0_ where dogs0_.owner=? and dogs0_.type='0002'
49:46,582 DEBUG BatcherImpl:249 - preparing statement
49:46,582 DEBUG Loader:402 - result set contains (possibly empty) collection: [model.Person.dogs#1]
49:46,582 DEBUG SessionImpl:3018 - uninitialized collection: initializing
49:46,582 DEBUG Loader:277 - processing result set
49:46,592 DEBUG Loader:480 - result row: 2
49:46,592 DEBUG Loader:611 - Initializing object from ResultSet: 2
49:46,592 DEBUG Loader:680 - Hydrating entity: model.Dog#2
49:46,592 DEBUG SessionImpl:1910 - Version: 10
49:46,592 DEBUG Loader:367 - found row of collection: [model.Person.dogs#1]
49:46,592 DEBUG SessionImpl:3041 - reading row
49:46,592 DEBUG SessionImpl:1986 - loading [model.Pet#2]
49:46,592 DEBUG SessionImpl:2083 - attempting to resolve [model.Pet#2]
49:46,592 DEBUG SessionImpl:2099 - resolved object in session cache [model.Pet#2]
49:46,602 DEBUG Loader:480 - result row: 3
49:46,602 DEBUG Loader:611 - Initializing object from ResultSet: 3
49:46,602 DEBUG Loader:680 - Hydrating entity: model.Dog#3
49:46,602 DEBUG SessionImpl:1910 - Version: 8
49:46,602 DEBUG Loader:367 - found row of collection: [model.Person.dogs#1]
49:46,602 DEBUG SessionImpl:3041 - reading row
49:46,602 DEBUG SessionImpl:1986 - loading [model.Pet#3]
49:46,602 DEBUG SessionImpl:2083 - attempting to resolve [model.Pet#3]
49:46,602 DEBUG SessionImpl:2099 - resolved object in session cache [model.Pet#3]
49:46,602 DEBUG Loader:480 - result row: 4
49:46,602 DEBUG Loader:611 - Initializing object from ResultSet: 4
49:46,602 DEBUG Loader:680 - Hydrating entity: model.Dog#4
49:46,602 DEBUG SessionImpl:1910 - Version: 7
49:46,612 DEBUG Loader:367 - found row of collection: [model.Person.dogs#1]
49:46,612 DEBUG SessionImpl:3041 - reading row
49:46,612 DEBUG SessionImpl:1986 - loading [model.Pet#4]
49:46,612 DEBUG SessionImpl:2083 - attempting to resolve [model.Pet#4]
49:46,612 DEBUG SessionImpl:2099 - resolved object in session cache [model.Pet#4]
49:46,612 DEBUG Loader:294 - done processing result set (3 rows)
49:46,612 DEBUG BatcherImpl:207 - done closing: 0 open PreparedStatements, 0 open ResultSets
49:46,612 DEBUG BatcherImpl:269 - closing statement
49:46,612 DEBUG Loader:314 - total objects hydrated: 3
49:46,612 DEBUG SessionImpl:2202 - resolving associations for [model.Dog#2]
49:46,612 DEBUG SessionImpl:1986 - loading [model.Person#1]
49:46,612 DEBUG SessionImpl:2083 - attempting to resolve [model.Person#1]
49:46,612 DEBUG SessionImpl:2099 - resolved object in session cache [model.Person#1]
49:46,612 DEBUG SessionImpl:2226 - done materializing entity [model.Dog#2]
49:46,622 DEBUG SessionImpl:2202 - resolving associations for [model.Dog#3]
49:46,622 DEBUG SessionImpl:1986 - loading [model.Person#1]
49:46,622 DEBUG SessionImpl:2083 - attempting to resolve [model.Person#1]
49:46,622 DEBUG SessionImpl:2099 - resolved object in session cache [model.Person#1]
49:46,622 DEBUG SessionImpl:2226 - done materializing entity [model.Dog#3]
49:46,622 DEBUG SessionImpl:2202 - resolving associations for [model.Dog#4]
49:46,622 DEBUG SessionImpl:1986 - loading [model.Person#1]
49:46,622 DEBUG SessionImpl:2083 - attempting to resolve [model.Person#1]
49:46,622 DEBUG SessionImpl:2099 - resolved object in session cache [model.Person#1]
49:46,622 DEBUG SessionImpl:2226 - done materializing entity [model.Dog#4]
49:46,622 DEBUG SessionImpl:3077 - 1 collections were found in result set
49:46,622 DEBUG SessionImpl:3095 - collection fully initialized: [model.Person.dogs#1]
49:46,622 DEBUG SessionImpl:3098 - 1 collections initialized
49:46,622 DEBUG SessionImpl:3269 - collection initialized
49:46,622 DEBUG SessionImpl:3260 - initializing collection [model.Person.cats#1]
49:46,632 DEBUG SessionImpl:3261 - checking second-level cache
49:46,632 DEBUG SessionImpl:3267 - collection not cached
49:46,632 DEBUG BatcherImpl:200 - about to open: 0 open PreparedStatements, 0 open ResultSets
49:46,632 DEBUG SQL:226 - select cats0_.owner as owner__, cats0_.id as id__, cats0_.id as id0_, cats0_.type as type0_, cats0_.version as version0_, cats0_.owner as owner0_, cats0_.name as name0_, cats0_.cat_fld as cat_fld0_, cats0_.dog_fld as dog_fld0_ from pet cats0_ where cats0_.owner=? and cats0_.type='0001'
Hibernate: select cats0_.owner as owner__, cats0_.id as id__, cats0_.id as id0_, cats0_.type as type0_, cats0_.version as version0_, cats0_.owner as owner0_, cats0_.name as name0_, cats0_.cat_fld as cat_fld0_, cats0_.dog_fld as dog_fld0_ from pet cats0_ where cats0_.owner=? and cats0_.type='0001'
49:46,632 DEBUG BatcherImpl:249 - preparing statement
49:46,632 DEBUG Loader:402 - result set contains (possibly empty) collection: [model.Person.cats#1]
49:46,632 DEBUG SessionImpl:3018 - uninitialized collection: initializing
49:46,632 DEBUG Loader:277 - processing result set
49:46,632 DEBUG Loader:480 - result row: 1
49:46,642 DEBUG Loader:611 - Initializing object from ResultSet: 1
49:46,642 DEBUG Loader:680 - Hydrating entity: model.Cat#1
49:46,642 DEBUG SessionImpl:1910 - Version: 10
49:46,642 DEBUG Loader:367 - found row of collection: [model.Person.cats#1]
49:46,642 DEBUG SessionImpl:3041 - reading row
49:46,642 DEBUG SessionImpl:1986 - loading [model.Pet#1]
49:46,642 DEBUG SessionImpl:2083 - attempting to resolve [model.Pet#1]
49:46,642 DEBUG SessionImpl:2099 - resolved object in session cache [model.Pet#1]
49:46,642 DEBUG Loader:294 - done processing result set (1 rows)
49:46,642 DEBUG BatcherImpl:207 - done closing: 0 open PreparedStatements, 0 open ResultSets
49:46,642 DEBUG BatcherImpl:269 - closing statement
49:46,642 DEBUG Loader:314 - total objects hydrated: 1
49:46,642 DEBUG SessionImpl:2202 - resolving associations for [model.Cat#1]
49:46,642 DEBUG SessionImpl:1986 - loading [model.Person#1]
49:46,642 DEBUG SessionImpl:2083 - attempting to resolve [model.Person#1]
49:46,642 DEBUG SessionImpl:2099 - resolved object in session cache [model.Person#1]
49:46,642 DEBUG SessionImpl:2226 - done materializing entity [model.Cat#1]
49:46,642 DEBUG SessionImpl:3077 - 1 collections were found in result set
49:46,652 DEBUG SessionImpl:3095 - collection fully initialized: [model.Person.cats#1]
49:46,652 DEBUG SessionImpl:3098 - 1 collections initialized
49:46,652 DEBUG SessionImpl:3269 - collection initialized
49:46,652 DEBUG JDBCTransaction:59 - commit
49:46,652 DEBUG SessionImpl:2246 - flushing session
49:46,652 DEBUG Cascades:497 - processing cascades for: model.Person
49:46,672 DEBUG Cascades:524 - cascading to collection: model.Person.cats
49:46,672 DEBUG Cascades:113 - cascading to saveOrUpdate()
49:46,672 DEBUG SessionImpl:1372 - saveOrUpdate() persistent instance
49:46,672 DEBUG Cascades:524 - cascading to collection: model.Person.dogs
49:46,682 DEBUG Cascades:113 - cascading to saveOrUpdate()
49:46,682 DEBUG SessionImpl:1372 - saveOrUpdate() persistent instance
49:46,682 DEBUG Cascades:113 - cascading to saveOrUpdate()
49:46,682 DEBUG SessionImpl:1372 - saveOrUpdate() persistent instance
49:46,682 DEBUG Cascades:113 - cascading to saveOrUpdate()
49:46,682 DEBUG SessionImpl:1372 - saveOrUpdate() persistent instance
49:46,682 DEBUG Cascades:506 - done processing cascades for: model.Person
49:46,682 DEBUG SessionImpl:2439 - Flushing entities and processing referenced collections
49:46,692 DEBUG SessionImpl:2884 - Collection found: [model.Person.cats#1], was: [model.Person.cats#1]
49:46,692 DEBUG SessionImpl:2884 - Collection found: [model.Person.dogs#1], was: [model.Person.dogs#1]
49:46,692 DEBUG SessionImpl:2780 - Processing unreferenced collections
49:46,692 DEBUG SessionImpl:2794 - Scheduling collection removes/(re)creates/updates
49:46,692 DEBUG SessionImpl:2270 - Flushed: 0 insertions, 0 updates, 0 deletions to 5 objects
49:46,692 DEBUG SessionImpl:2275 - Flushed: 0 (re)creations, 0 updates, 0 removals to 2 collections
49:46,692 DEBUG Printer:75 - listing entities:
49:46,692 DEBUG Printer:82 - model.Dog{owner=Person#1, dogFld=yip, name=Ruff, id=4, version=7}
49:46,692 DEBUG Printer:82 - model.Cat{owner=Person#1, name=Fluffy, catFld=purr, id=1, version=10}
49:46,702 DEBUG Printer:82 - model.Person{cats=[Cat#1], dogs=[Dog#3, Dog#4, Dog#2], name=joe, id=1, version=12}
49:46,702 DEBUG Printer:82 - model.Dog{owner=Person#1, dogFld=woof, name=Fido, id=3, version=8}
49:46,702 DEBUG Printer:82 - model.Dog{owner=Person#1, dogFld=bark, name=Bowser, id=2, version=10}
49:46,702 DEBUG SessionImpl:2359 - executing flush
49:46,702 DEBUG SessionImpl:2824 - post flush
49:46,702 DEBUG SessionImpl:585 - transaction completion
49:46,702 DEBUG SessionImpl:573 - closing session
49:46,702 DEBUG SessionImpl:3336 - disconnecting session
49:46,702 DEBUG DriverManagerConnectionProvider:120 - returning connection to pool, pool size: 1
49:46,702 DEBUG SessionImpl:585 - transaction completion
!!!Got person Person[id=1, version=12, name='joe', cats={Cat[Pet[id=1, version=10, name='Fluffy'], catFld='purr']}, dogs={Dog[Pet[id=3, version=8, name='Fido'], dogFld='woof'],Dog[Pet[id=4, version=7, name='Ruff'], dogFld='yip'],Dog[Pet[id=2, version=10, name='Bowser'], dogFld='bark']}]
49:46,712 DEBUG SessionImpl:555 - opened session
49:46,712 DEBUG JDBCTransaction:37 - begin
49:46,712 DEBUG DriverManagerConnectionProvider:84 - total checked-out connections: 0
49:46,712 DEBUG DriverManagerConnectionProvider:90 - using pooled JDBC connection, pool size: 0
49:46,712 DEBUG JDBCTransaction:41 - current autocommit status:false
49:46,712 DEBUG Cascades:396 - version unsaved-value strategy UNDEFINED
49:46,712 DEBUG Cascades:341 - id unsaved-value strategy NULL
49:46,712 DEBUG SessionImpl:1392 - saveOrUpdate() previously saved instance with id: 1
49:46,712 DEBUG SessionImpl:1440 - updating [model.Person#1]
49:46,712 DEBUG Cascades:497 - processing cascades for: model.Person
49:46,712 DEBUG Cascades:524 - cascading to collection: model.Person.cats
49:46,712 DEBUG Cascades:113 - cascading to saveOrUpdate()
49:46,712 DEBUG Cascades:396 - version unsaved-value strategy UNDEFINED
49:46,712 DEBUG Cascades:341 - id unsaved-value strategy NULL
49:46,712 DEBUG SessionImpl:1392 - saveOrUpdate() previously saved instance with id: 1
49:46,712 DEBUG SessionImpl:1440 - updating [model.Cat#1]
49:46,722 DEBUG Cascades:524 - cascading to collection: model.Person.dogs
49:46,722 DEBUG Cascades:113 - cascading to saveOrUpdate()
49:46,722 DEBUG Cascades:396 - version unsaved-value strategy UNDEFINED
49:46,722 DEBUG Cascades:341 - id unsaved-value strategy NULL
49:46,722 DEBUG SessionImpl:1392 - saveOrUpdate() previously saved instance with id: 3
49:46,722 DEBUG SessionImpl:1440 - updating [model.Dog#3]
49:46,722 DEBUG Cascades:113 - cascading to saveOrUpdate()
49:46,722 DEBUG Cascades:396 - version unsaved-value strategy UNDEFINED
49:46,722 DEBUG Cascades:341 - id unsaved-value strategy NULL
49:46,722 DEBUG SessionImpl:1392 - saveOrUpdate() previously saved instance with id: 4
49:46,722 DEBUG SessionImpl:1440 - updating [model.Dog#4]
49:46,722 DEBUG Cascades:113 - cascading to saveOrUpdate()
49:46,722 DEBUG Cascades:396 - version unsaved-value strategy UNDEFINED
49:46,722 DEBUG Cascades:341 - id unsaved-value strategy NULL
49:46,722 DEBUG SessionImpl:1392 - saveOrUpdate() previously saved instance with id: 2
49:46,722 DEBUG SessionImpl:1440 - updating [model.Dog#2]
49:46,722 DEBUG Cascades:506 - done processing cascades for: model.Person
49:46,722 DEBUG JDBCTransaction:59 - commit
49:46,722 DEBUG SessionImpl:2246 - flushing session
49:46,722 DEBUG Cascades:497 - processing cascades for: model.Person
49:46,722 DEBUG Cascades:524 - cascading to collection: model.Person.cats
49:46,722 DEBUG Cascades:113 - cascading to saveOrUpdate()
49:46,722 DEBUG SessionImpl:1372 - saveOrUpdate() persistent instance
49:46,722 DEBUG Cascades:524 - cascading to collection: model.Person.dogs
49:46,722 DEBUG Cascades:113 - cascading to saveOrUpdate()
49:46,732 DEBUG SessionImpl:1372 - saveOrUpdate() persistent instance
49:46,732 DEBUG Cascades:113 - cascading to saveOrUpdate()
49:46,732 DEBUG SessionImpl:1372 - saveOrUpdate() persistent instance
49:46,732 DEBUG Cascades:113 - cascading to saveOrUpdate()
49:46,732 DEBUG SessionImpl:1372 - saveOrUpdate() persistent instance
49:46,732 DEBUG Cascades:506 - done processing cascades for: model.Person
49:46,732 DEBUG SessionImpl:2439 - Flushing entities and processing referenced collections
49:46,732 DEBUG AbstractEntityPersister:1245 - Getting current persistent state for: [model.Person#1]
49:46,732 DEBUG BatcherImpl:200 - about to open: 0 open PreparedStatements, 0 open ResultSets
49:46,732 DEBUG SQL:226 - select id, version, name from person where id =? and version =?
Hibernate: select id, version, name from person where id =? and version =?
49:46,732 DEBUG BatcherImpl:249 - preparing statement
49:46,732 DEBUG BatcherImpl:207 - done closing: 0 open PreparedStatements, 0 open ResultSets
49:46,732 DEBUG BatcherImpl:269 - closing statement
49:46,732 DEBUG SessionImpl:2884 - Collection found: [model.Person.cats#1], was: [model.Person.cats#1]
49:46,732 DEBUG SessionImpl:2884 - Collection found: [model.Person.dogs#1], was: [model.Person.dogs#1]
49:46,742 DEBUG SessionImpl:2533 - Updating entity: [model.Cat#1]
49:46,742 DEBUG Versioning:26 - Incrementing: 10 to 11
49:46,742 DEBUG SessionImpl:2533 - Updating entity: [model.Dog#3]
49:46,742 DEBUG Versioning:26 - Incrementing: 8 to 9
49:46,742 DEBUG SessionImpl:2533 - Updating entity: [model.Dog#4]
49:46,742 DEBUG Versioning:26 - Incrementing: 7 to 8
49:46,742 DEBUG SessionImpl:2533 - Updating entity: [model.Dog#2]
49:46,742 DEBUG Versioning:26 - Incrementing: 10 to 11
49:46,742 DEBUG SessionImpl:2780 - Processing unreferenced collections
49:46,742 DEBUG SessionImpl:2794 - Scheduling collection removes/(re)creates/updates
49:46,742 DEBUG SessionImpl:2270 - Flushed: 0 insertions, 4 updates, 0 deletions to 5 objects
49:46,742 DEBUG SessionImpl:2275 - Flushed: 0 (re)creations, 0 updates, 0 removals to 2 collections
49:46,742 DEBUG Printer:75 - listing entities:
49:46,742 DEBUG Printer:82 - model.Dog{owner=Person#1, dogFld=yip, name=Ruff, id=4, version=7}
49:46,742 DEBUG Printer:82 - model.Cat{owner=Person#1, name=Fluffy, catFld=purr, id=1, version=10}
49:46,742 DEBUG Printer:82 - model.Person{cats=[Cat#1], dogs=[Dog#3, Dog#4, Dog#2], name=joe, id=1, version=12}
49:46,742 DEBUG Printer:82 - model.Dog{owner=Person#1, dogFld=woof, name=Fido, id=3, version=8}
49:46,752 DEBUG Printer:82 - model.Dog{owner=Person#1, dogFld=bark, name=Bowser, id=2, version=10}
49:46,752 DEBUG SessionImpl:2359 - executing flush
49:46,752 DEBUG EntityPersister:648 - Updating entity: [model.Cat#1]
49:46,752 DEBUG EntityPersister:649 - Existing version: 10 -> New version: 11
49:46,752 DEBUG BatcherImpl:200 - about to open: 0 open PreparedStatements, 0 open ResultSets
49:46,752 DEBUG SQL:226 - update pet set cat_fld=?, version=?, owner=?, name=? where id=? and version=?
Hibernate: update pet set cat_fld=?, version=?, owner=?, name=? where id=? and version=?
49:46,752 DEBUG BatcherImpl:249 - preparing statement
49:46,772 DEBUG EntityPersister:388 - Dehydrating entity: [model.Cat#1]
49:46,772 DEBUG BatcherImpl:207 - done closing: 0 open PreparedStatements, 0 open ResultSets
49:46,772 DEBUG BatcherImpl:269 - closing statement
49:46,772 DEBUG EntityPersister:648 - Updating entity: [model.Dog#3]
49:46,772 DEBUG EntityPersister:649 - Existing version: 8 -> New version: 9
49:46,772 DEBUG BatcherImpl:200 - about to open: 0 open PreparedStatements, 0 open ResultSets
49:46,772 DEBUG SQL:226 - update pet set dog_fld=?, version=?, owner=?, name=? where id=? and version=?
Hibernate: update pet set dog_fld=?, version=?, owner=?, name=? where id=? and version=?
49:46,772 DEBUG BatcherImpl:249 - preparing statement
49:46,772 DEBUG EntityPersister:388 - Dehydrating entity: [model.Dog#3]
49:46,782 DEBUG BatcherImpl:207 - done closing: 0 open PreparedStatements, 0 open ResultSets
49:46,782 DEBUG BatcherImpl:269 - closing statement
49:46,782 DEBUG EntityPersister:648 - Updating entity: [model.Dog#4]
49:46,782 DEBUG EntityPersister:649 - Existing version: 7 -> New version: 8
49:46,782 DEBUG BatcherImpl:200 - about to open: 0 open PreparedStatements, 0 open ResultSets
49:46,782 DEBUG SQL:226 - update pet set dog_fld=?, version=?, owner=?, name=? where id=? and version=?
Hibernate: update pet set dog_fld=?, version=?, owner=?, name=? where id=? and version=?
49:46,782 DEBUG BatcherImpl:249 - preparing statement
49:46,782 DEBUG EntityPersister:388 - Dehydrating entity: [model.Dog#4]
49:46,782 DEBUG BatcherImpl:207 - done closing: 0 open PreparedStatements, 0 open ResultSets
49:46,782 DEBUG BatcherImpl:269 - closing statement
49:46,782 DEBUG EntityPersister:648 - Updating entity: [model.Dog#2]
49:46,782 DEBUG EntityPersister:649 - Existing version: 10 -> New version: 11
49:46,782 DEBUG BatcherImpl:200 - about to open: 0 open PreparedStatements, 0 open ResultSets
49:46,782 DEBUG SQL:226 - update pet set dog_fld=?, version=?, owner=?, name=? where id=? and version=?
Hibernate: update pet set dog_fld=?, version=?, owner=?, name=? where id=? and version=?
49:46,782 DEBUG BatcherImpl:249 - preparing statement
49:46,792 DEBUG EntityPersister:388 - Dehydrating entity: [model.Dog#2]
49:46,792 DEBUG BatcherImpl:207 - done closing: 0 open PreparedStatements, 0 open ResultSets
49:46,792 DEBUG BatcherImpl:269 - closing statement
49:46,792 DEBUG SessionImpl:2824 - post flush
49:46,792 DEBUG SessionImpl:585 - transaction completion
49:46,792 DEBUG SessionImpl:573 - closing session
49:46,792 DEBUG SessionImpl:3336 - disconnecting session
49:46,792 DEBUG DriverManagerConnectionProvider:120 - returning connection to pool, pool size: 1
49:46,792 DEBUG SessionImpl:585 - transaction completion

Top

gavin

Post subject:

Posted: Fri Sep 03, 2004 8:00 pm

Hibernate Team

Joined: Tue Aug 26, 2003 12:50 pm
Posts: 5130
Location: Melbourne, Australia

ick, DTD bug - edit the DTD to allow select-before-update on <subclass> and <joined-subclass> elements

Top

Page 1 of 1

[ 2 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