-->
These old forums are deprecated now and set to read-only. We are waiting for you on our new forums!
More modern, Discourse-based and with GitHub/Google/Twitter authentication built-in.

View unanswered posts | View active topics


Board index » Hibernate & Java Persistence » Hibernate Users

All times are UTC - 5 hours [ DST ]


Forum locked This topic is locked, you cannot edit posts or make further replies.  Page 1 of 1
  [ 2 posts ] 
  Previous topic | Next topic 
Author Message
equality72521
 Post subject: Yet another Many-To-Many idbag question...
PostPosted: Fri Jun 02, 2006 10:39 pm 
Newbie

Joined: Fri Jun 02, 2006 9:31 pm
Posts: 7
I’m wondering if the following behavior is by design, or if I’ve mapped something incorrectly. I recreated the venerable “category/item” many-to-many relationship as described in the reference docs:
Category (1…* ) Category_Item (*…1) Item

The Category_Item table has a surrogate primary key and two foreign keys to the related tables. I’ve replicated this same issue using an “increment” generator (since identities still don’t work with idbags….right?) on MySQL 5 and a “sequence” on Oracle 9.2

For my purposes, the relationship is unidirectional from the Category – I’ll want to see all the items in a Category, but never really want to see all the Categories tied to an Item.

What I’m trying to do in the test code below is remove a single Item from a Category. I don’t want to delete the Item, just the relationship (in the CATEGORY_ITEM table). My test data has 1 Category and 5 Items, all tied to the 1 Category. When I run this code, it actually works as expected – the relationship for the Item I removed from the collection is deleted and I’m left with 4 relationships left in the table. However, when I go through the debug trace I see that Hibernate first deleted ALL of the relationships, then reinserted the 4. While the end result is accurate, it seems terribly inefficient. Based on the reference docs, I understand that Hibernate behaves like this with a regular Bag since it doesn’t have any key information, but it seems to do the same thing with an idbag (for which I’ve provided a collection-id).

I already read http://forum.hibernate.org/viewtopic.php?t=297 thinking I had a similar issue, but implementing equals()/hashcode() had no effect.

Am I doing something wrong, or is this the intended behavior?

Insights?

Thanks for any help! It's much appreciated!

Hibernate version:
3.1.3

Tables (MySQL):
Code:
CREATE TABLE  `manytomany`.`category` (
  `CATEGORYID` int(10) unsigned NOT NULL auto_increment,
  `NAME` varchar(45) NOT NULL default '',
  PRIMARY KEY  (`CATEGORYID`)
) ENGINE=InnoDB DEFAULT CHARSET=latin1;

CREATE TABLE  `manytomany`.`item` (
  `ITEMID` int(10) unsigned NOT NULL auto_increment,
  `NAME` varchar(45) NOT NULL default '',
  PRIMARY KEY  (`ITEMID`)
) ENGINE=InnoDB DEFAULT CHARSET=latin1;

CREATE TABLE  `manytomany`.`category_item` (
  `CATEGORY_ITEMID` int(10) unsigned NOT NULL,
  `CATEGORYID` int(10) unsigned NOT NULL default '0',
  `ITEMID` int(10) unsigned NOT NULL default '0',
  PRIMARY KEY  (`CATEGORY_ITEMID`),
  KEY `FK_CATEGORY_ITEM_1` (`CATEGORYID`),
  KEY `FK_category_item_2` (`ITEMID`),
  CONSTRAINT `FK_CATEGORY_ITEM_1` FOREIGN KEY (`CATEGORYID`) REFERENCES `category` (`CATEGORYID`),
  CONSTRAINT `FK_category_item_2` FOREIGN KEY (`ITEMID`) REFERENCES `item` (`ITEMID`)
) ENGINE=InnoDB DEFAULT CHARSET=latin1;

Mapping documents:
Code:
<?xml version="1.0" encoding="UTF-8"?>
<!DOCTYPE hibernate-mapping PUBLIC "-//Hibernate/Hibernate Mapping DTD 3.0//EN"
   "http://hibernate.sourceforge.net/hibernate-mapping-3.0.dtd">

<hibernate-mapping default-lazy="false" package="test.ManyToMany" default-access="field">
   <class name="Category" table="CATEGORY">
      <id name="categoryID" column="CATEGORYID" type="long">
         <generator class="identity"/>
      </id>
      <property name="name" column="NAME" type="string" not-null="true"/>
      
      <idbag name="items" table="CATEGORY_ITEM" cascade="save-update">
         <collection-id column="CATEGORY_ITEMID" type="long">
            <generator class="increment"/>
         </collection-id>
         <key column="CATEGORYID"/>
         <many-to-many column="ITEMID" class="Item" fetch="join"/>
      </idbag>
   </class>

   <class name="Item" table="ITEM">
      <id name="itemID" column="ITEMID" type="long">
         <generator class="identity"/>
      </id>
      <property name="name" column="NAME" type="string" not-null="true"/>
   </class>
</hibernate-mapping>


Classes:
Code:
public class Category {
   private Long categoryID;
   private String name;
   private List items = new ArrayList();

   public Long getCategoryID() {return categoryID;}
   
   public String getName() {return name;}
   public void setName(String name) {this.name = name;}
   
   public List getItems() {return Collections.unmodifiableList(items);}
   public void addItem(Item item) {items.add(item);}
   public void removeItem(Item item) {items.remove(item);}
   
   public boolean equals(Object obj) {
      if (obj instanceof Category == false) {return false;}
      if (this == obj) {return true;}
      
      Category rhs = (Category) obj;
      return new EqualsBuilder()
         .appendSuper(super.equals(obj))
         .append(categoryID, rhs.getName())
         .append(name, rhs.getName())
         .isEquals();
   }
   
   public int hashCode() {
      return new HashCodeBuilder(17, 37)
      .append(categoryID)
      .append(name)
      .toHashCode();
   }
}

public class Item {
   private Long itemID;
   private String name;
   
   public Long getItemID() {return itemID;}
   
   public String getName() {return name;}
   public void setName(String name) {this.name = name;}
   
   public boolean equals(Object obj) {
      if (obj instanceof Item == false) {return false;}
      if (this == obj) {return true;}
      
      Item rhs = (Item) obj;
      return new EqualsBuilder()
         .appendSuper(super.equals(obj))
         .append(itemID, rhs.getItemID())
         .append(name, rhs.getName())
         .isEquals();
   }
   
   public int hashCode() {
      return new HashCodeBuilder(17, 37)
      .append(itemID)
      .append(name)
      .toHashCode();
   }
}

public class test {
   public static void main(String[] args) {
      SessionFactory sessionFactory = new Configuration().configure().buildSessionFactory();
      Session session = sessionFactory.getCurrentSession();
      session.beginTransaction();
      Category category = (Category)session.createQuery("from Category").list().iterator().next();
      
      Item item = (Item)category.getItems().iterator().next();
      category.removeItem(item);

      session.merge(category);
      
      session.flush();
      
      session.getTransaction().rollback();
   }
}


Name and version of the database you are using:
MySQL 5.0.21 (or Oracle 9.2.0.3)
MySQL Connector 3.1.12
Oracle9i 9.2.0.5 JDBC Drivers

Trace:
(Sorry, it's long... Posting the whole thing in case I'm mapping/loading something incorrectly...)

[code]22:05:19,000 INFO Environment:479 - Hibernate 3.1.3
22:05:19,015 INFO Environment:509 - hibernate.properties not found
22:05:19,015 INFO Environment:525 - using CGLIB reflection optimizer
22:05:19,015 INFO Environment:555 - using JDK 1.4 java.sql.Timestamp handling
22:05:19,093 INFO Configuration:1308 - configuring from resource: /hibernate.cfg.xml
22:05:19,093 INFO Configuration:1285 - Configuration resource: /hibernate.cfg.xml
22:05:19,375 DEBUG DTDEntityResolver:22 - trying to resolve system-id [http://hibernate.sourceforge.net/hibernate-configuration-3.0.dtd]
22:05:19,375 DEBUG DTDEntityResolver:24 - recognized hibernate namespace; attempting to resolve on classpath under org/hibernate/
22:05:19,375 DEBUG DTDEntityResolver:34 - located [http://hibernate.sourceforge.net/hibernate-configuration-3.0.dtd] in classpath
22:05:19,421 DEBUG Configuration:1269 - connection.driver_class=com.mysql.jdbc.Driver
22:05:19,421 DEBUG Configuration:1269 - connection.url=jdbc:mysql://localhost:3306/ManyToMany
22:05:19,437 DEBUG Configuration:1269 - connection.username=ManyToMany
22:05:19,437 DEBUG Configuration:1269 - connection.password=ManyToMany
22:05:19,437 DEBUG Configuration:1269 - connection.pool_size=1
22:05:19,437 DEBUG Configuration:1269 - dialect=org.hibernate.dialect.HSQLDialect
22:05:19,437 DEBUG Configuration:1269 - current_session_context_class=thread
22:05:19,437 DEBUG Configuration:1269 - cache.provider_class=org.hibernate.cache.NoCacheProvider
22:05:19,437 DEBUG Configuration:1269 - show_sql=true
22:05:19,437 DEBUG Configuration:1464 - null<-org.dom4j.tree.DefaultAttribute@186db54 [Attribute: name resource value "ManyToMany.hbm.xml"]
22:05:19,437 INFO Configuration:469 - Reading mappings from resource: ManyToMany.hbm.xml
22:05:19,437 DEBUG DTDEntityResolver:22 - trying to resolve system-id [http://hibernate.sourceforge.net/hibernate-mapping-3.0.dtd]
22:05:19,437 DEBUG DTDEntityResolver:24 - recognized hibernate namespace; attempting to resolve on classpath under org/hibernate/
22:05:19,437 DEBUG DTDEntityResolver:34 - located [http://hibernate.sourceforge.net/hibernate-mapping-3.0.dtd] in classpath
22:05:19,578 INFO HbmBinder:309 - Mapping class: test.ManyToMany.Category -> CATEGORY
22:05:19,593 DEBUG HbmBinder:1261 - Mapped property: categoryID -> CATEGORYID
22:05:19,593 DEBUG HbmBinder:1261 - Mapped property: name -> NAME
22:05:19,609 INFO HbmBinder:1397 - Mapping collection: test.ManyToMany.Category.items -> CATEGORY_ITEM
22:05:19,609 DEBUG HbmBinder:1261 - Mapped property: items
22:05:19,609 INFO HbmBinder:309 - Mapping class: test.ManyToMany.Item -> ITEM
22:05:19,609 DEBUG HbmBinder:1261 - Mapped property: itemID -> ITEMID
22:05:19,609 DEBUG HbmBinder:1261 - Mapped property: name -> NAME
22:05:19,609 INFO Configuration:1419 - Configured SessionFactory: null
22:05:19,609 DEBUG Configuration:1420 - properties: {hibernate.connection.password=ManyToMany, java.runtime.name=Java(TM) 2 Runtime Environment, Standard Edition, hibernate.cache.provider_class=org.hibernate.cache.NoCacheProvider, sun.boot.library.path=C:\Java\jdk1.5.0_06\jre\bin, java.vm.version=1.5.0_06-b05, hibernate.connection.username=ManyToMany, 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=US, sun.os.patch.level=Service Pack 2, java.vm.specification.name=Java Virtual Machine Specification, user.dir=C:\Java\_Sandbox\ManyToMany, java.runtime.version=1.5.0_06-b05, java.awt.graphicsenv=sun.awt.Win32GraphicsEnvironment, hibernate.current_session_context_class=thread, java.endorsed.dirs=C:\Java\jdk1.5.0_06\jre\lib\endorsed, os.arch=x86, java.io.tmpdir=C:\DOCUME~1\Dave\LOCALS~1\Temp\, line.separator=
, java.vm.specification.vendor=Sun Microsystems Inc., cache.provider_class=org.hibernate.cache.NoCacheProvider, user.variant=, os.name=Windows XP, sun.jnu.encoding=Cp1252, java.library.path=C:\Java\jdk1.5.0_06\bin;.;C:\WINDOWS\system32;C:\WINDOWS;C:\WINDOWS\system32;C:\WINDOWS;C:\WINDOWS\System32\Wbem;C:\Program Files\Common Files\Roxio Shared\DLLShared\;, java.specification.name=Java Platform API Specification, java.class.version=49.0, hibernate.connection.pool_size=1, sun.management.compiler=HotSpot Client Compiler, os.version=5.1, connection.password=ManyToMany, user.home=C:\Documents and Settings\Dave, user.timezone=America/New_York, connection.username=ManyToMany, java.awt.printerjob=sun.awt.windows.WPrinterJob, file.encoding=Cp1252, java.specification.version=1.5, hibernate.connection.driver_class=com.mysql.jdbc.Driver, show_sql=true, user.name=Dave, java.class.path=C:\Java\_Sandbox\ManyToMany\bin;C:\Java\_Sandbox\ManyToMany\lib\ant-1.6.5.jar;C:\Java\_Sandbox\ManyToMany\lib\ant-antlr-1.6.5.jar;C:\Java\_Sandbox\ManyToMany\lib\ant-junit-1.6.5.jar;C:\Java\_Sandbox\ManyToMany\lib\ant-launcher-1.6.5.jar;C:\Java\_Sandbox\ManyToMany\lib\antlr-2.7.6rc1.jar;C:\Java\_Sandbox\ManyToMany\lib\ant-swing-1.6.5.jar;C:\Java\_Sandbox\ManyToMany\lib\asm.jar;C:\Java\_Sandbox\ManyToMany\lib\asm-attrs.jar;C:\Java\_Sandbox\ManyToMany\lib\c3p0-0.9.0.jar;C:\Java\_Sandbox\ManyToMany\lib\cglib-2.1.3.jar;C:\Java\_Sandbox\ManyToMany\lib\cleanimports.jar;C:\Java\_Sandbox\ManyToMany\lib\commons-collections-2.1.1.jar;C:\Java\_Sandbox\ManyToMany\lib\commons-logging-1.0.4.jar;C:\Java\_Sandbox\ManyToMany\lib\concurrent-1.3.2.jar;C:\Java\_Sandbox\ManyToMany\lib\connector.jar;C:\Java\_Sandbox\ManyToMany\lib\dom4j-1.6.1.jar;C:\Java\_Sandbox\ManyToMany\lib\ehcache-1.1.jar;C:\Java\_Sandbox\ManyToMany\lib\hibernate3.jar;C:\Java\_Sandbox\ManyToMany\lib\jaas.jar;C:\Java\_Sandbox\ManyToMany\lib\jacc-1_0-fr.jar;C:\Java\_Sandbox\ManyToMany\lib\jaxen-1.1-beta-7.jar;C:\Java\_Sandbox\ManyToMany\lib\jboss-cache.jar;C:\Java\_Sandbox\ManyToMany\lib\jboss-common.jar;C:\Java\_Sandbox\ManyToMany\lib\jboss-jmx.jar;C:\Java\_Sandbox\ManyToMany\lib\jboss-system.jar;C:\Java\_Sandbox\ManyToMany\lib\jdbc2_0-stdext.jar;C:\Java\_Sandbox\ManyToMany\lib\jgroups-2.2.8.jar;C:\Java\_Sandbox\ManyToMany\lib\jta.jar;C:\Java\_Sandbox\ManyToMany\lib\junit-3.8.1.jar;C:\Java\_Sandbox\ManyToMany\lib\log4j-1.2.11.jar;C:\Java\_Sandbox\ManyToMany\lib\oscache-2.1.jar;C:\Java\_Sandbox\ManyToMany\lib\proxool-0.8.3.jar;C:\Java\_Sandbox\ManyToMany\lib\swarmcache-1.0rc2.jar;C:\Java\_Sandbox\ManyToMany\lib\syndiag2.jar;C:\Java\_Sandbox\ManyToMany\lib\versioncheck.jar;C:\Java\_Sandbox\ManyToMany\lib\xerces-2.6.2.jar;C:\Java\_Sandbox\ManyToMany\lib\xml-apis.jar;C:\Java\_Sandbox\ManyToMany\lib\mysql-connector-java-3.1.12-bin.jar;C:\Java\_Sandbox\ManyToMany\lib\commons-lang.jar, hibernate.show_sql=true, current_session_context_class=thread, java.vm.specification.version=1.0, java.home=C:\Java\jdk1.5.0_06\jre, sun.arch.data.model=32, hibernate.dialect=org.hibernate.dialect.HSQLDialect, hibernate.connection.url=jdbc:mysql://localhost:3306/ManyToMany, connection.pool_size=1, 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, sharing, java.version=1.5.0_06, java.ext.dirs=C:\Java\jdk1.5.0_06\jre\lib\ext, sun.boot.class.path=C:\Java\jdk1.5.0_06\jre\lib\rt.jar;C:\Java\jdk1.5.0_06\jre\lib\i18n.jar;C:\Java\jdk1.5.0_06\jre\lib\sunrsasign.jar;C:\Java\jdk1.5.0_06\jre\lib\jsse.jar;C:\Java\jdk1.5.0_06\jre\lib\jce.jar;C:\Java\jdk1.5.0_06\jre\lib\charsets.jar;C:\Java\jdk1.5.0_06\jre\classes, java.vendor=Sun Microsystems Inc., connection.driver_class=com.mysql.jdbc.Driver, file.separator=\, java.vendor.url.bug=http://java.sun.com/cgi-bin/bugreport.cgi, sun.io.unicode.encoding=UnicodeLittle, sun.cpu.endian=little, sun.desktop=windows, connection.url=jdbc:mysql://localhost:3306/ManyToMany, dialect=org.hibernate.dialect.HSQLDialect, sun.cpu.isalist=}
22:05:19,609 DEBUG Configuration:1167 - Preparing to build session factory with filters : {}
22:05:19,609 DEBUG Configuration:1002 - processing extends queue
22:05:19,609 DEBUG Configuration:1006 - processing collection mappings
22:05:19,609 DEBUG CollectionSecondPass:33 - Second pass for collection: test.ManyToMany.Category.items
22:05:19,687 DEBUG CollectionSecondPass:49 - Mapped collection key: CATEGORYID, element: ITEMID
22:05:19,687 DEBUG Configuration:1017 - processing native query and ResultSetMapping mappings
22:05:19,687 DEBUG Configuration:1025 - processing association property references
22:05:19,687 DEBUG Configuration:1047 - processing foreign key constraints
22:05:19,687 DEBUG Configuration:1130 - resolving reference to class: test.ManyToMany.Item
22:05:19,687 DEBUG Configuration:1130 - resolving reference to class: test.ManyToMany.Category
22:05:19,703 INFO DriverManagerConnectionProvider:41 - Using Hibernate built-in connection pool (not for production use!)
22:05:19,703 INFO DriverManagerConnectionProvider:42 - Hibernate connection pool size: 1
22:05:19,703 INFO DriverManagerConnectionProvider:45 - autocommit mode: false
22:05:19,718 INFO DriverManagerConnectionProvider:80 - using driver: com.mysql.jdbc.Driver at URL: jdbc:mysql://localhost:3306/ManyToMany
22:05:19,718 INFO DriverManagerConnectionProvider:83 - connection properties: {user=ManyToMany, password=ManyToMany}
22:05:19,718 DEBUG DriverManagerConnectionProvider:93 - total checked-out connections: 0
22:05:19,718 DEBUG DriverManagerConnectionProvider:109 - opening new JDBC connection
22:05:19,984 DEBUG DriverManagerConnectionProvider:115 - created connection to: jdbc:mysql://localhost:3306/ManyToMany, Isolation Level: 4
22:05:19,984 INFO SettingsFactory:77 - RDBMS: MySQL, version: 5.0.19-nt
22:05:19,984 INFO SettingsFactory:78 - JDBC driver: MySQL-AB JDBC Driver, version: mysql-connector-java-3.1.12 ( $Date: 2005-11-17 15:53:48 +0100 (Thu, 17 Nov 2005) $, $Revision$ )
22:05:19,984 DEBUG DriverManagerConnectionProvider:129 - returning connection to pool, pool size: 1
22:05:20,015 INFO Dialect:103 - Using dialect: org.hibernate.dialect.HSQLDialect
22:05:20,031 INFO TransactionFactoryFactory:31 - Using default transaction strategy (direct JDBC transactions)
22:05:20,031 INFO TransactionManagerLookupFactory:33 - No TransactionManagerLookup configured (in JTA environment, use of read-write or transactional second-level cache is not recommended)
22:05:20,031 INFO SettingsFactory:125 - Automatic flush during beforeCompletion(): disabled
22:05:20,031 INFO SettingsFactory:129 - Automatic session close at end of transaction: disabled
22:05:20,031 INFO SettingsFactory:136 - JDBC batch size: 15
22:05:20,031 INFO SettingsFactory:139 - JDBC batch updates for versioned data: disabled
22:05:20,031 INFO SettingsFactory:144 - Scrollable result sets: enabled
22:05:20,031 DEBUG SettingsFactory:148 - Wrap result sets: disabled
22:05:20,031 INFO SettingsFactory:152 - JDBC3 getGeneratedKeys(): enabled
22:05:20,031 INFO SettingsFactory:160 - Connection release mode: auto
22:05:20,031 INFO SettingsFactory:187 - Default batch fetch size: 1
22:05:20,031 INFO SettingsFactory:191 - Generate SQL with comments: disabled
22:05:20,031 INFO SettingsFactory:195 - Order SQL updates by primary key: disabled
22:05:20,031 INFO SettingsFactory:338 - Query translator: org.hibernate.hql.ast.ASTQueryTranslatorFactory
22:05:20,046 INFO ASTQueryTranslatorFactory:24 - Using ASTQueryTranslatorFactory
22:05:20,046 INFO SettingsFactory:203 - Query language substitutions: {}
22:05:20,046 INFO SettingsFactory:209 - Second-level cache: enabled
22:05:20,046 INFO SettingsFactory:213 - Query cache: disabled
22:05:20,046 INFO SettingsFactory:325 - Cache provider: org.hibernate.cache.NoCacheProvider
22:05:20,046 INFO SettingsFactory:228 - Optimize cache for minimal puts: disabled
22:05:20,046 INFO SettingsFactory:237 - Structured second-level cache entries: disabled
22:05:20,046 DEBUG SQLExceptionConverterFactory:52 - Using dialect defined converter
22:05:20,062 INFO SettingsFactory:257 - Echoing all SQL to stdout
22:05:20,062 INFO SettingsFactory:264 - Statistics: disabled
22:05:20,062 INFO SettingsFactory:268 - Deleted entity synthetic identifier rollback: disabled
22:05:20,062 INFO SettingsFactory:283 - Default entity-mode: pojo
22:05:20,093 INFO SessionFactoryImpl:154 - building session factory
22:05:20,093 DEBUG SessionFactoryImpl:165 - Session factory constructed with filter configurations : {}
22:05:20,093 DEBUG SessionFactoryImpl:168 - instantiating session factory with properties: {java.runtime.name=Java(TM) 2 Runtime Environment, Standard Edition, hibernate.connection.password=ManyToMany, hibernate.cache.provider_class=org.hibernate.cache.NoCacheProvider, sun.boot.library.path=C:\Java\jdk1.5.0_06\jre\bin, java.vm.version=1.5.0_06-b05, hibernate.connection.username=ManyToMany, 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=US, sun.os.patch.level=Service Pack 2, java.vm.specification.name=Java Virtual Machine Specification, user.dir=C:\Java\_Sandbox\ManyToMany, java.runtime.version=1.5.0_06-b05, java.awt.graphicsenv=sun.awt.Win32GraphicsEnvironment, hibernate.current_session_context_class=thread, java.endorsed.dirs=C:\Java\jdk1.5.0_06\jre\lib\endorsed, os.arch=x86, java.io.tmpdir=C:\DOCUME~1\Dave\LOCALS~1\Temp\, line.separator=
, java.vm.specification.vendor=Sun Microsystems Inc., user.variant=, cache.provider_class=org.hibernate.cache.NoCacheProvider, os.name=Windows XP, sun.jnu.encoding=Cp1252, java.library.path=C:\Java\jdk1.5.0_06\bin;.;C:\WINDOWS\system32;C:\WINDOWS;C:\WINDOWS\system32;C:\WINDOWS;C:\WINDOWS\System32\Wbem;C:\Program Files\Common Files\Roxio Shared\DLLShared\;, java.specification.name=Java Platform API Specification, java.class.version=49.0, hibernate.connection.pool_size=1, sun.management.compiler=HotSpot Client Compiler, os.version=5.1, user.home=C:\Documents and Settings\Dave, connection.password=ManyToMany, user.timezone=America/New_York, java.awt.printerjob=sun.awt.windows.WPrinterJob, connection.username=ManyToMany, java.specification.version=1.5, file.encoding=Cp1252, hibernate.connection.driver_class=com.mysql.jdbc.Driver, show_sql=true, java.class.path=C:\Java\_Sandbox\ManyToMany\bin;C:\Java\_Sandbox\ManyToMany\lib\ant-1.6.5.jar;C:\Java\_Sandbox\ManyToMany\lib\ant-antlr-1.6.5.jar;C:\Java\_Sandbox\ManyToMany\lib\ant-junit-1.6.5.jar;C:\Java\_Sandbox\ManyToMany\lib\ant-launcher-1.6.5.jar;C:\Java\_Sandbox\ManyToMany\lib\antlr-2.7.6rc1.jar;C:\Java\_Sandbox\ManyToMany\lib\ant-swing-1.6.5.jar;C:\Java\_Sandbox\ManyToMany\lib\asm.jar;C:\Java\_Sandbox\ManyToMany\lib\asm-attrs.jar;C:\Java\_Sandbox\ManyToMany\lib\c3p0-0.9.0.jar;C:\Java\_Sandbox\ManyToMany\lib\cglib-2.1.3.jar;C:\Java\_Sandbox\ManyToMany\lib\cleanimports.jar;C:\Java\_Sandbox\ManyToMany\lib\commons-collections-2.1.1.jar;C:\Java\_Sandbox\ManyToMany\lib\commons-logging-1.0.4.jar;C:\Java\_Sandbox\ManyToMany\lib\concurrent-1.3.2.jar;C:\Java\_Sandbox\ManyToMany\lib\connector.jar;C:\Java\_Sandbox\ManyToMany\lib\dom4j-1.6.1.jar;C:\Java\_Sandbox\ManyToMany\lib\ehcache-1.1.jar;C:\Java\_Sandbox\ManyToMany\lib\hibernate3.jar;C:\Java\_Sandbox\ManyToMany\lib\jaas.jar;C:\Java\_Sandbox\ManyToMany\lib\jacc-1_0-fr.jar;C:\Java\_Sandbox\ManyToMany\lib\jaxen-1.1-beta-7.jar;C:\Java\_Sandbox\ManyToMany\lib\jboss-cache.jar;C:\Java\_Sandbox\ManyToMany\lib\jboss-common.jar;C:\Java\_Sandbox\ManyToMany\lib\jboss-jmx.jar;C:\Java\_Sandbox\ManyToMany\lib\jboss-system.jar;C:\Java\_Sandbox\ManyToMany\lib\jdbc2_0-stdext.jar;C:\Java\_Sandbox\ManyToMany\lib\jgroups-2.2.8.jar;C:\Java\_Sandbox\ManyToMany\lib\jta.jar;C:\Java\_Sandbox\ManyToMany\lib\junit-3.8.1.jar;C:\Java\_Sandbox\ManyToMany\lib\log4j-1.2.11.jar;C:\Java\_Sandbox\ManyToMany\lib\oscache-2.1.jar;C:\Java\_Sandbox\ManyToMany\lib\proxool-0.8.3.jar;C:\Java\_Sandbox\ManyToMany\lib\swarmcache-1.0rc2.jar;C:\Java\_Sandbox\ManyToMany\lib\syndiag2.jar;C:\Java\_Sandbox\ManyToMany\lib\versioncheck.jar;C:\Java\_Sandbox\ManyToMany\lib\xerces-2.6.2.jar;C:\Java\_Sandbox\ManyToMany\lib\xml-apis.jar;C:\Java\_Sandbox\ManyToMany\lib\mysql-connector-java-3.1.12-bin.jar;C:\Java\_Sandbox\ManyToMany\lib\commons-lang.jar, user.name=Dave, hibernate.show_sql=true, current_session_context_class=thread, java.vm.specification.version=1.0, sun.arch.data.model=32, java.home=C:\Java\jdk1.5.0_06\jre, hibernate.connection.url=jdbc:mysql://localhost:3306/ManyToMany, hibernate.dialect=org.hibernate.dialect.HSQLDialect, java.specification.vendor=Sun Microsystems Inc., user.language=en, connection.pool_size=1, awt.toolkit=sun.awt.windows.WToolkit, java.vm.info=mixed mode, sharing, hibernate.cglib.use_reflection_optimizer=true, java.version=1.5.0_06, java.ext.dirs=C:\Java\jdk1.5.0_06\jre\lib\ext, sun.boot.class.path=C:\Java\jdk1.5.0_06\jre\lib\rt.jar;C:\Java\jdk1.5.0_06\jre\lib\i18n.jar;C:\Java\jdk1.5.0_06\jre\lib\sunrsasign.jar;C:\Java\jdk1.5.0_06\jre\lib\jsse.jar;C:\Java\jdk1.5.0_06\jre\lib\jce.jar;C:\Java\jdk1.5.0_06\jre\lib\charsets.jar;C:\Java\jdk1.5.0_06\jre\classes, java.vendor=Sun Microsystems Inc., file.separator=\, connection.driver_class=com.mysql.jdbc.Driver, java.vendor.url.bug=http://java.sun.com/cgi-bin/bugreport.cgi, sun.cpu.endian=little, sun.io.unicode.encoding=UnicodeLittle, sun.desktop=windows, connection.url=jdbc:mysql://localhost:3306/ManyToMany, sun.cpu.isalist=, dialect=org.hibernate.dialect.HSQLDialect}
22:05:20,250 DEBUG AbstractEntityPersister:2447 - Static SQL for entity: test.ManyToMany.Item
22:05:20,265 DEBUG AbstractEntityPersister:2449 - Version select: select ITEMID from ITEM where ITEMID =?
22:05:20,265 DEBUG AbstractEntityPersister:2450 - Snapshot select: select item_.ITEMID, item_.NAME as NAME2_ from ITEM item_ where item_.ITEMID=?
22:05:20,265 DEBUG AbstractEntityPersister:2452 - Insert 0: insert into ITEM (NAME, ITEMID) values (?, ?)
22:05:20,265 DEBUG AbstractEntityPersister:2453 - Update 0: update ITEM set NAME=? where ITEMID=?
22:05:20,265 DEBUG AbstractEntityPersister:2454 - Delete 0: delete from ITEM where ITEMID=?
22:05:20,265 DEBUG AbstractEntityPersister:2457 - Identity insert: insert into ITEM (NAME, ITEMID) values (?, null)
22:05:20,265 DEBUG AbstractEntityPersister:2447 - Static SQL for entity: test.ManyToMany.Category
22:05:20,265 DEBUG AbstractEntityPersister:2449 - Version select: select CATEGORYID from CATEGORY where CATEGORYID =?
22:05:20,265 DEBUG AbstractEntityPersister:2450 - Snapshot select: select category_.CATEGORYID, category_.NAME as NAME0_ from CATEGORY category_ where category_.CATEGORYID=?
22:05:20,265 DEBUG AbstractEntityPersister:2452 - Insert 0: insert into CATEGORY (NAME, CATEGORYID) values (?, ?)
22:05:20,265 DEBUG AbstractEntityPersister:2453 - Update 0: update CATEGORY set NAME=? where CATEGORYID=?
22:05:20,265 DEBUG AbstractEntityPersister:2454 - Delete 0: delete from CATEGORY where CATEGORYID=?
22:05:20,265 DEBUG AbstractEntityPersister:2457 - Identity insert: insert into CATEGORY (NAME, CATEGORYID) values (?, null)
22:05:20,281 DEBUG AbstractCollectionPersister:511 - Static SQL for collection: test.ManyToMany.Category.items
22:05:20,281 DEBUG AbstractCollectionPersister:512 - Row insert: insert into CATEGORY_ITEM (CATEGORYID, CATEGORY_ITEMID, ITEMID) values (?, ?, ?)
22:05:20,281 DEBUG AbstractCollectionPersister:513 - Row update: update CATEGORY_ITEM set ITEMID=? where CATEGORY_ITEMID=?
22:05:20,281 DEBUG AbstractCollectionPersister:514 - Row delete: delete from CATEGORY_ITEM where CATEGORY_ITEMID=?
22:05:20,281 DEBUG AbstractCollectionPersister:515 - One-shot delete: delete from CATEGORY_ITEM where CATEGORYID=?
22:05:20,312 DEBUG EntityLoader:79 - Static select for entity test.ManyToMany.Item: select item0_.ITEMID as ITEMID2_0_, item0_.NAME as NAME2_0_ from ITEM item0_ where item0_.ITEMID=?
22:05:20,312 DEBUG EntityLoader:79 - Static select for entity test.ManyToMany.Item: select item0_.ITEMID as ITEMID2_0_, item0_.NAME as NAME2_0_ from ITEM item0_ where item0_.ITEMID=?
22:05:20,312 DEBUG EntityLoader:79 - Static select for entity test.ManyToMany.Item: select item0_.ITEMID as ITEMID2_0_, item0_.NAME as NAME2_0_ from ITEM item0_ where item0_.ITEMID=?
22:05:20,312 DEBUG EntityLoader:79 - Static select for entity test.ManyToMany.Item: select item0_.ITEMID as ITEMID2_0_, item0_.NAME as NAME2_0_ from ITEM item0_ where item0_.ITEMID=?
22:05:20,328 DEBUG EntityLoader:34 - Static select for action ACTION_MERGE on entity test.ManyToMany.Item: select item0_.ITEMID as ITEMID2_0_, item0_.NAME as NAME2_0_ from ITEM item0_ where item0_.ITEMID=?
22:05:20,328 DEBUG EntityLoader:34 - Static select for action ACTION_REFRESH on entity test.ManyToMany.Item: select item0_.ITEMID as ITEMID2_0_, item0_.NAME as NAME2_0_ from ITEM item0_ where item0_.ITEMID=?
22:05:20,328 DEBUG EntityLoader:79 - Static select for entity test.ManyToMany.Category: select category0_.CATEGORYID as CATEGORYID0_0_, category0_.NAME as NAME0_0_ from CATEGORY category0_ where category0_.CATEGORYID=?
22:05:20,328 DEBUG EntityLoader:79 - Static select for entity test.ManyToMany.Category: select category0_.CATEGORYID as CATEGORYID0_0_, category0_.NAME as NAME0_0_ from CATEGORY category0_ where category0_.CATEGORYID=?
22:05:20,328 DEBUG EntityLoader:79 - Static select for entity test.ManyToMany.Category: select category0_.CATEGORYID as CATEGORYID0_0_, category0_.NAME as NAME0_0_ from CATEGORY category0_ where category0_.CATEGORYID=?
22:05:20,328 DEBUG EntityLoader:79 - Static select for entity test.ManyToMany.Category: select category0_.CATEGORYID as CATEGORYID0_0_, category0_.NAME as NAME0_0_ from CATEGORY category0_ where category0_.CATEGORYID=?
22:05:20,328 DEBUG EntityLoader:34 - Static select for action ACTION_MERGE on entity test.ManyToMany.Category: select category0_.CATEGORYID as CATEGORYID0_0_, category0_.NAME as NAME0_0_ from CATEGORY category0_ where category0_.CATEGORYID=?
22:05:20,328 DEBUG EntityLoader:34 - Static select for action ACTION_REFRESH on entity test.ManyToMany.Category: select category0_.CATEGORYID as CATEGORYID0_0_, category0_.NAME as NAME0_0_ from CATEGORY category0_ where category0_.CATEGORYID=?
22:05:20,328 DEBUG BasicCollectionLoader:64 - Static select for collection test.ManyToMany.Category.items: select items0_.CATEGORYID as CATEGORYID1_, items0_.ITEMID as ITEMID1_, items0_.CATEGORY_ITEMID as CATEGORY3_1_, item1_.ITEMID as ITEMID2_0_, item1_.NAME as NAME2_0_ from CATEGORY_ITEM items0_ left outer join ITEM item1_ on items0_.ITEMID=item1_.ITEMID where items0_.CATEGORYID=?
22:05:20,343 DEBUG SessionFactoryObjectFactory:39 - initializing class SessionFactoryObjectFactory
22:05:20,343 DEBUG SessionFactoryObjectFactory:76 - registered: 402881e40b97a327010b97a328570000 (unnamed)
22:05:20,343 INFO SessionFactoryObjectFactory:82 - Not binding factory to JNDI, no JNDI name configured
22:05:20,343 DEBUG SessionFactoryImpl:293 - instantiated session factory
22:05:20,343 DEBUG SessionFactoryImpl:354 - Checking 0 named HQL queries
22:05:20,343 DEBUG SessionFactoryImpl:374 - Checking 0 named SQL queries
22:05:20,390 DEBUG SessionImpl:219 - opened session at timestamp: 11493003203
22:05:20,484 DEBUG ThreadLocalSessionContext:290 - allowing method [beginTransaction] in non-transacted context
22:05:20,484 DEBUG ThreadLocalSessionContext:300 - allowing proxied method [beginTransaction] to proceed to real session
22:05:20,484 DEBUG JDBCTransaction:54 - begin
22:05:20,531 DEBUG ConnectionManager:415 - opening JDBC connection
22:05:20,531 DEBUG DriverManagerConnectionProvider:93 - total checked-out connections: 0
22:05:20,531 DEBUG DriverManagerConnectionProvider:99 - using pooled JDBC connection, pool size: 0
22:05:20,531 DEBUG JDBCTransaction:59 - current autocommit status: false
22:05:20,531 DEBUG JDBCContext:194 - after transaction begin
22:05:20,531 DEBUG ThreadLocalSessionContext:300 - allowing proxied method [createQuery] to proceed to real session
22:05:20,531 DEBUG QueryPlanCache:69 - unable to locate HQL query plan in cache; generating (from Category)
22:05:20,609 DEBUG QueryTranslatorImpl:236 - parse() - HQL: from test.ManyToMany.Category
22:05:20,625 DEBUG AST:252 - --- HQL AST ---
\-[QUERY] 'query'
\-[SELECT_FROM] 'SELECT_FROM'
\-[FROM] 'from'
\-[RANGE] 'RANGE'
\-[DOT] '.'
+-[DOT] '.'
| +-[IDENT] 'test'
| \-[IDENT] 'ManyToMany'
\-[IDENT] 'Category'

22:05:20,625 DEBUG ErrorCounter:68 - throwQueryException() : no errors
22:05:20,671 DEBUG HqlSqlBaseWalker:111 - select << begin [level=1, statement=select]
22:05:20,703 DEBUG FromElement:104 - FromClause{level=1} : test.ManyToMany.Category (no alias) -> category0_
22:05:20,703 DEBUG HqlSqlBaseWalker:117 - select : finishing up [level=1, statement=select]
22:05:20,703 DEBUG HqlSqlWalker:511 - processQuery() : ( SELECT ( FromClause{level=1} CATEGORY category0_ ) )
22:05:20,718 DEBUG HqlSqlWalker:713 - Derived SELECT clause created.
22:05:20,718 DEBUG JoinProcessor:128 - Using FROM fragment [CATEGORY category0_]
22:05:20,718 DEBUG HqlSqlBaseWalker:123 - select >> end [level=1, statement=select]
22:05:20,734 DEBUG AST:222 - --- SQL AST ---
\-[SELECT] QueryNode: 'SELECT' querySpaces (CATEGORY)
+-[SELECT_CLAUSE] SelectClause: '{derived select clause}'
| +-[SELECT_EXPR] SelectExpressionImpl: 'category0_.CATEGORYID as CATEGORYID0_' {FromElement{explicit,not a collection join,not a fetch join,fetch non-lazy properties,classAlias=null,role=null,tableName=CATEGORY,tableAlias=category0_,origin=null,colums={,className=test.ManyToMany.Category}}}
| \-[SQL_TOKEN] SqlFragment: 'category0_.NAME as NAME0_'
\-[FROM] FromClause: 'from' FromClause{level=1, fromElementCounter=1, fromElements=1, fromElementByClassAlias=[], fromElementByTableAlias=[category0_], fromElementsByPath=[], collectionJoinFromElementsByPath=[], impliedElements=[]}
\-[FROM_FRAGMENT] FromElement: 'CATEGORY category0_' FromElement{explicit,not a collection join,not a fetch join,fetch non-lazy properties,classAlias=null,role=null,tableName=CATEGORY,tableAlias=category0_,origin=null,colums={,className=test.ManyToMany.Category}}

22:05:20,734 DEBUG ErrorCounter:68 - throwQueryException() : no errors
22:05:20,750 DEBUG QueryTranslatorImpl:206 - HQL: from test.ManyToMany.Category
22:05:20,750 DEBUG QueryTranslatorImpl:207 - SQL: select category0_.CATEGORYID as CATEGORYID0_, category0_.NAME as NAME0_ from CATEGORY category0_
22:05:20,750 DEBUG ErrorCounter:68 - throwQueryException() : no errors
22:05:20,750 DEBUG HQLQueryPlan:219 - HQL param location recognition took 0 mills (from Category)
22:05:20,765 DEBUG QueryPlanCache:75 - located HQL query plan in cache (from Category)
22:05:20,765 DEBUG HQLQueryPlan:148 - find: from Category
22:05:20,765 DEBUG QueryParameters:262 - named parameters: {}
22:05:20,765 DEBUG AbstractBatcher:311 - about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
22:05:20,765 DEBUG SQL:346 - select category0_.CATEGORYID as CATEGORYID0_, category0_.NAME as NAME0_ from CATEGORY category0_
Hibernate: select category0_.CATEGORYID as CATEGORYID0_, category0_.NAME as NAME0_ from CATEGORY category0_
22:05:20,765 DEBUG AbstractBatcher:424 - preparing statement
22:05:20,781 DEBUG AbstractBatcher:327 - about to open ResultSet (open ResultSets: 0, globally: 0)
22:05:20,781 DEBUG Loader:682 - processing result set
22:05:20,781 DEBUG Loader:687 - result set row: 0
22:05:20,781 DEBUG LongType:122 - returning '1' as column: CATEGORYID0_
22:05:20,781 DEBUG Loader:1164 - result row: EntityKey[test.ManyToMany.Category#1]
22:05:20,781 DEBUG Loader:1347 - Initializing object from ResultSet: [test.ManyToMany.Category#1]
22:05:20,796 DEBUG AbstractEntityPersister:1860 - Hydrating entity: [test.ManyToMany.Category#1]
22:05:20,796 DEBUG StringType:122 - returning 'Test Category' as column: NAME0_
22:05:20,796 DEBUG Loader:709 - done processing result set (1 rows)
22:05:20,796 DEBUG AbstractBatcher:334 - about to close ResultSet (open ResultSets: 1, globally: 1)
22:05:20,796 DEBUG AbstractBatcher:319 - about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
22:05:20,796 DEBUG AbstractBatcher:470 - closing statement
22:05:20,796 DEBUG Loader:839 - total objects hydrated: 1
22:05:20,796 DEBUG TwoPhaseLoad:107 - resolving associations for [test.ManyToMany.Category#1]
22:05:20,812 DEBUG CollectionLoadContext:141 - creating collection wrapper:[test.ManyToMany.Category.items#1]
22:05:20,812 DEBUG TwoPhaseLoad:206 - done materializing entity [test.ManyToMany.Category#1]
22:05:20,812 DEBUG StatefulPersistenceContext:748 - initializing non-lazy collections
22:05:20,812 DEBUG DefaultInitializeCollectionEventListener:41 - initializing collection [test.ManyToMany.Category.items#1]
22:05:20,812 DEBUG DefaultInitializeCollectionEventListener:47 - checking second-level cache
22:05:20,812 DEBUG DefaultInitializeCollectionEventListener:59 - collection not cached
22:05:20,812 DEBUG Loader:1911 - loading collection: [test.ManyToMany.Category.items#1]
22:05:20,812 DEBUG AbstractBatcher:311 - about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
22:05:20,812 DEBUG SQL:346 - select items0_.CATEGORYID as CATEGORYID1_, items0_.ITEMID as ITEMID1_, items0_.CATEGORY_ITEMID as CATEGORY3_1_, item1_.ITEMID as ITEMID2_0_, item1_.NAME as NAME2_0_ from CATEGORY_ITEM items0_ left outer join ITEM item1_ on items0_.ITEMID=item1_.ITEMID where items0_.CATEGORYID=?
Hibernate: select items0_.CATEGORYID as CATEGORYID1_, items0_.ITEMID as ITEMID1_, items0_.CATEGORY_ITEMID as CATEGORY3_1_, item1_.ITEMID as ITEMID2_0_, item1_.NAME as NAME2_0_ from CATEGORY_ITEM items0_ left outer join ITEM item1_ on items0_.ITEMID=item1_.ITEMID where items0_.CATEGORYID=?
22:05:20,812 DEBUG AbstractBatcher:424 - preparing statement
22:05:20,828 DEBUG LongType:80 - binding '1' to parameter: 1
22:05:20,828 DEBUG AbstractBatcher:327 - about to open ResultSet (open ResultSets: 0, globally: 0)
22:05:20,828 DEBUG Loader:1040 - result set contains (possibly empty) collection: [test.ManyToMany.Category.items#1]
22:05:20,828 DEBUG CollectionLoadContext:84 - uninitialized collection: initializing
22:05:20,828 DEBUG Loader:682 - processing result set
22:05:20,828 DEBUG Loader:687 - result set row: 0
22:05:20,828 DEBUG LongType:122 - returning '1' as column: ITEMID2_0_
22:05:20,828 DEBUG Loader:1164 - result row: EntityKey[test.ManyToMany.Item#1]
22:05:20,828 DEBUG Loader:1347 - Initializing object from ResultSet: [test.ManyToMany.Item#1]
22:05:20,828 DEBUG AbstractEntityPersister:1860 - Hydrating entity: [test.ManyToMany.Item#1]
22:05:20,828 DEBUG StringType:122 - returning 'Item1' as column: NAME2_0_
22:05:20,828 DEBUG LongType:122 - returning '1' as column: CATEGORYID1_
22:05:20,828 DEBUG Loader:972 - found row of collection: [test.ManyToMany.Category.items#1]
22:05:20,828 DEBUG CollectionLoadContext:112 - reading row
22:05:20,828 DEBUG LongType:122 - returning '1' as column: ITEMID1_
22:05:20,828 DEBUG DefaultLoadEventListener:153 - loading entity: [test.ManyToMany.Item#1]
22:05:20,828 DEBUG DefaultLoadEventListener:304 - attempting to resolve: [test.ManyToMany.Item#1]
22:05:20,828 DEBUG DefaultLoadEventListener:313 - resolved object in session cache: [test.ManyToMany.Item#1]
22:05:20,843 DEBUG LongType:122 - returning '1' as column: CATEGORY3_1_
22:05:20,843 DEBUG Loader:687 - result set row: 1
22:05:20,843 DEBUG LongType:122 - returning '2' as column: ITEMID2_0_
22:05:20,843 DEBUG Loader:1164 - result row: EntityKey[test.ManyToMany.Item#2]
22:05:20,843 DEBUG Loader:1347 - Initializing object from ResultSet: [test.ManyToMany.Item#2]
22:05:20,843 DEBUG AbstractEntityPersister:1860 - Hydrating entity: [test.ManyToMany.Item#2]
22:05:20,843 DEBUG StringType:122 - returning 'Item2' as column: NAME2_0_
22:05:20,843 DEBUG LongType:122 - returning '1' as column: CATEGORYID1_
22:05:20,843 DEBUG Loader:972 - found row of collection: [test.ManyToMany.Category.items#1]
22:05:20,843 DEBUG CollectionLoadContext:112 - reading row
22:05:20,843 DEBUG LongType:122 - returning '2' as column: ITEMID1_
22:05:20,843 DEBUG DefaultLoadEventListener:153 - loading entity: [test.ManyToMany.Item#2]
22:05:20,843 DEBUG DefaultLoadEventListener:304 - attempting to resolve: [test.ManyToMany.Item#2]
22:05:20,843 DEBUG DefaultLoadEventListener:313 - resolved object in session cache: [test.ManyToMany.Item#2]
22:05:20,843 DEBUG LongType:122 - returning '2' as column: CATEGORY3_1_
22:05:20,843 DEBUG Loader:687 - result set row: 2
22:05:20,843 DEBUG LongType:122 - returning '3' as column: ITEMID2_0_
22:05:20,843 DEBUG Loader:1164 - result row: EntityKey[test.ManyToMany.Item#3]
22:05:20,843 DEBUG Loader:1347 - Initializing object from ResultSet: [test.ManyToMany.Item#3]
22:05:20,843 DEBUG AbstractEntityPersister:1860 - Hydrating entity: [test.ManyToMany.Item#3]
22:05:20,843 DEBUG StringType:122 - returning 'Item3' as column: NAME2_0_
22:05:20,843 DEBUG LongType:122 - returning '1' as column: CATEGORYID1_
22:05:20,843 DEBUG Loader:972 - found row of collection: [test.ManyToMany.Category.items#1]
22:05:20,843 DEBUG CollectionLoadContext:112 - reading row
22:05:20,843 DEBUG LongType:122 - returning '3' as column: ITEMID1_
22:05:20,843 DEBUG DefaultLoadEventListener:153 - loading entity: [test.ManyToMany.Item#3]
22:05:20,843 DEBUG DefaultLoadEventListener:304 - attempting to resolve: [test.ManyToMany.Item#3]
22:05:20,843 DEBUG DefaultLoadEventListener:313 - resolved object in session cache: [test.ManyToMany.Item#3]
22:05:20,859 DEBUG LongType:122 - returning '3' as column: CATEGORY3_1_
22:05:20,859 DEBUG Loader:687 - result set row: 3
22:05:20,859 DEBUG LongType:122 - returning '4' as column: ITEMID2_0_
22:05:20,859 DEBUG Loader:1164 - result row: EntityKey[test.ManyToMany.Item#4]
22:05:20,859 DEBUG Loader:1347 - Initializing object from ResultSet: [test.ManyToMany.Item#4]
22:05:20,859 DEBUG AbstractEntityPersister:1860 - Hydrating entity: [test.ManyToMany.Item#4]
22:05:20,859 DEBUG StringType:122 - returning 'Item4' as column: NAME2_0_
22:05:20,859 DEBUG LongType:122 - returning '1' as column: CATEGORYID1_
22:05:20,859 DEBUG Loader:972 - found row of collection: [test.ManyToMany.Category.items#1]
22:05:20,859 DEBUG CollectionLoadContext:112 - reading row
22:05:20,859 DEBUG LongType:122 - returning '4' as column: ITEMID1_
22:05:20,859 DEBUG DefaultLoadEventListener:153 - loading entity: [test.ManyToMany.Item#4]
22:05:20,859 DEBUG DefaultLoadEventListener:304 - attempting to resolve: [test.ManyToMany.Item#4]
22:05:20,859 DEBUG DefaultLoadEventListener:313 - resolved object in session cache: [test.ManyToMany.Item#4]
22:05:20,859 DEBUG LongType:122 - returning '4' as column: CATEGORY3_1_
22:05:20,859 DEBUG Loader:687 - result set row: 4
22:05:20,859 DEBUG LongType:122 - returning '5' as column: ITEMID2_0_
22:05:20,859 DEBUG Loader:1164 - result row: EntityKey[test.ManyToMany.Item#5]
22:05:20,859 DEBUG Loader:1347 - Initializing object from ResultSet: [test.ManyToMany.Item#5]
22:05:20,859 DEBUG AbstractEntityPersister:1860 - Hydrating entity: [test.ManyToMany.Item#5]
22:05:20,859 DEBUG StringType:122 - returning 'Item5' as column: NAME2_0_
22:05:20,859 DEBUG LongType:122 - returning '1' as column: CATEGORYID1_
22:05:20,859 DEBUG Loader:972 - found row of collection: [test.ManyToMany.Category.items#1]
22:05:20,859 DEBUG CollectionLoadContext:112 - reading row
22:05:20,859 DEBUG LongType:122 - returning '5' as column: ITEMID1_
22:05:20,859 DEBUG DefaultLoadEventListener:153 - loading entity: [test.ManyToMany.Item#5]
22:05:20,859 DEBUG DefaultLoadEventListener:304 - attempting to resolve: [test.ManyToMany.Item#5]
22:05:20,859 DEBUG DefaultLoadEventListener:313 - resolved object in session cache: [test.ManyToMany.Item#5]
22:05:20,859 DEBUG LongType:122 - returning '5' as column: CATEGORY3_1_
22:05:20,859 DEBUG Loader:709 - done processing result set (5 rows)
22:05:20,875 DEBUG AbstractBatcher:334 - about to close ResultSet (open ResultSets: 1, globally: 1)
22:05:20,875 DEBUG AbstractBatcher:319 - about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
22:05:20,875 DEBUG AbstractBatcher:470 - closing statement
22:05:20,875 DEBUG Loader:839 - total objects hydrated: 5
22:05:20,875 DEBUG TwoPhaseLoad:107 - resolving associations for [test.ManyToMany.Item#1]
22:05:20,875 DEBUG TwoPhaseLoad:206 - done materializing entity [test.ManyToMany.Item#1]
22:05:20,875 DEBUG TwoPhaseLoad:107 - resolving associations for [test.ManyToMany.Item#2]
22:05:20,875 DEBUG TwoPhaseLoad:206 - done materializing entity [test.ManyToMany.Item#2]
22:05:20,875 DEBUG TwoPhaseLoad:107 - resolving associations for [test.ManyToMany.Item#3]
22:05:20,875 DEBUG TwoPhaseLoad:206 - done materializing entity [test.ManyToMany.Item#3]
22:05:20,875 DEBUG TwoPhaseLoad:107 - resolving associations for [test.ManyToMany.Item#4]
22:05:20,875 DEBUG TwoPhaseLoad:206 - done materializing entity [test.ManyToMany.Item#4]
22:05:20,875 DEBUG TwoPhaseLoad:107 - resolving associations for [test.ManyToMany.Item#5]
22:05:20,875 DEBUG TwoPhaseLoad:206 - done materializing entity [test.ManyToMany.Item#5]
22:05:20,875 DEBUG CollectionLoadContext:262 - 1 collections were found in result set for role: test.ManyToMany.Category.items
22:05:20,875 DEBUG CollectionLoadContext:206 - collection fully initialized: [test.ManyToMany.Category.items#1]
22:05:20,875 DEBUG CollectionLoadContext:272 - 1 collections initialized for role: test.ManyToMany.Category.items
22:05:20,875 DEBUG Loader:1935 - done loading collection
22:05:20,875 DEBUG DefaultInitializeCollectionEventListener:61 - collection initialized
22:05:20,875 DEBUG ThreadLocalSessionContext:300 - allowing proxied method [merge] to proceed to real session
22:05:20,875 DEBUG AbstractSaveEventListener:436 - persistent instance of: test.ManyToMany.Category
22:05:20,875 DEBUG DefaultMergeEventListener:122 - ignoring persistent instance
22:05:20,875 DEBUG Cascade:237 - processing cascade ACTION_MERGE for: test.ManyToMany.Category
22:05:20,875 DEBUG Cascade:259 - done processing cascade ACTION_MERGE for: test.ManyToMany.Category
22:05:20,890 DEBUG DefaultLoadEventListener:153 - loading entity: [test.ManyToMany.Item#2]
22:05:20,890 DEBUG DefaultLoadEventListener:304 - attempting to resolve: [test.ManyToMany.Item#2]
22:05:20,890 DEBUG DefaultLoadEventListener:313 - resolved object in session cache: [test.ManyToMany.Item#2]
22:05:20,890 DEBUG DefaultLoadEventListener:153 - loading entity: [test.ManyToMany.Item#3]
22:05:20,890 DEBUG DefaultLoadEventListener:304 - attempting to resolve: [test.ManyToMany.Item#3]
22:05:20,890 DEBUG DefaultLoadEventListener:313 - resolved object in session cache: [test.ManyToMany.Item#3]
22:05:20,890 DEBUG DefaultLoadEventListener:153 - loading entity: [test.ManyToMany.Item#4]
22:05:20,890 DEBUG DefaultLoadEventListener:304 - attempting to resolve: [test.ManyToMany.Item#4]
22:05:20,890 DEBUG DefaultLoadEventListener:313 - resolved object in session cache: [test.ManyToMany.Item#4]
22:05:20,890 DEBUG DefaultLoadEventListener:153 - loading entity: [test.ManyToMany.Item#5]
22:05:20,890 DEBUG DefaultLoadEventListener:304 - attempting to resolve: [test.ManyToMany.Item#5]
22:05:20,890 DEBUG DefaultLoadEventListener:313 - resolved object in session cache: [test.ManyToMany.Item#5]
22:05:20,890 DEBUG DefaultLoadEventListener:153 - loading entity: [test.ManyToMany.Item#2]
22:05:20,890 DEBUG DefaultLoadEventListener:304 - attempting to resolve: [test.ManyToMany.Item#2]
22:05:20,890 DEBUG DefaultLoadEventListener:313 - resolved object in session cache: [test.ManyToMany.Item#2]
22:05:20,890 DEBUG DefaultLoadEventListener:153 - loading entity: [test.ManyToMany.Item#3]
22:05:20,890 DEBUG DefaultLoadEventListener:304 - attempting to resolve: [test.ManyToMany.Item#3]
22:05:20,890 DEBUG DefaultLoadEventListener:313 - resolved object in session cache: [test.ManyToMany.Item#3]
22:05:20,890 DEBUG DefaultLoadEventListener:153 - loading entity: [test.ManyToMany.Item#4]
22:05:20,890 DEBUG DefaultLoadEventListener:304 - attempting to resolve: [test.ManyToMany.Item#4]
22:05:20,890 DEBUG DefaultLoadEventListener:313 - resolved object in session cache: [test.ManyToMany.Item#4]
22:05:20,890 DEBUG DefaultLoadEventListener:153 - loading entity: [test.ManyToMany.Item#5]
22:05:20,890 DEBUG DefaultLoadEventListener:304 - attempting to resolve: [test.ManyToMany.Item#5]
22:05:20,890 DEBUG DefaultLoadEventListener:313 - resolved object in session cache: [test.ManyToMany.Item#5]
22:05:20,890 DEBUG ThreadLocalSessionContext:300 - allowing proxied method [flush] to proceed to real session
22:05:20,890 DEBUG AbstractFlushingEventListener:58 - flushing session
22:05:20,890 DEBUG AbstractFlushingEventListener:111 - processing flush-time cascades
22:05:20,906 DEBUG Cascade:237 - processing cascade ACTION_SAVE_UPDATE for: test.ManyToMany.Category
22:05:20,906 DEBUG Cascade:285 - cascade ACTION_SAVE_UPDATE for collection: test.ManyToMany.Category.items
22:05:20,906 DEBUG CascadingAction:133 - cascading to saveOrUpdate: test.ManyToMany.Item
22:05:20,906 DEBUG AbstractSaveEventListener:436 - persistent instance of: test.ManyToMany.Item
22:05:20,906 DEBUG DefaultSaveOrUpdateEventListener:105 - ignoring persistent instance
22:05:20,906 DEBUG DefaultSaveOrUpdateEventListener:142 - object already associated with session: [test.ManyToMany.Item#2]
22:05:20,906 DEBUG CascadingAction:133 - cascading to saveOrUpdate: test.ManyToMany.Item
22:05:20,906 DEBUG AbstractSaveEventListener:436 - persistent instance of: test.ManyToMany.Item
22:05:20,906 DEBUG DefaultSaveOrUpdateEventListener:105 - ignoring persistent instance
22:05:20,906 DEBUG DefaultSaveOrUpdateEventListener:142 - object already associated with session: [test.ManyToMany.Item#3]
22:05:20,906 DEBUG CascadingAction:133 - cascading to saveOrUpdate: test.ManyToMany.Item
22:05:20,906 DEBUG AbstractSaveEventListener:436 - persistent instance of: test.ManyToMany.Item
22:05:20,906 DEBUG DefaultSaveOrUpdateEventListener:105 - ignoring persistent instance
22:05:20,906 DEBUG DefaultSaveOrUpdateEventListener:142 - object already associated with session: [test.ManyToMany.Item#4]
22:05:20,906 DEBUG CascadingAction:133 - cascading to saveOrUpdate: test.ManyToMany.Item
22:05:20,906 DEBUG AbstractSaveEventListener:436 - persistent instance of: test.ManyToMany.Item
22:05:20,906 DEBUG DefaultSaveOrUpdateEventListener:105 - ignoring persistent instance
22:05:20,906 DEBUG DefaultSaveOrUpdateEventListener:142 - object already associated with session: [test.ManyToMany.Item#5]
22:05:20,906 DEBUG Cascade:300 - done cascade ACTION_SAVE_UPDATE for collection: test.ManyToMany.Category.items
22:05:20,906 DEBUG Cascade:259 - done processing cascade ACTION_SAVE_UPDATE for: test.ManyToMany.Category
22:05:20,906 DEBUG AbstractFlushingEventListener:153 - dirty checking collections
22:05:20,906 DEBUG CollectionEntry:177 - Collection dirty: [test.ManyToMany.Category.items#1]
22:05:20,906 DEBUG AbstractFlushingEventListener:170 - Flushing entities and processing referenced collections
22:05:20,921 DEBUG Collections:176 - Collection found: [test.ManyToMany.Category.items#1], was: [test.ManyToMany.Category.items#1] (initialized)
22:05:20,921 DEBUG AbstractFlushingEventListener:209 - Processing unreferenced collections
22:05:20,921 DEBUG AbstractFlushingEventListener:223 - Scheduling collection removes/(re)creates/updates
22:05:20,921 DEBUG AbstractFlushingEventListener:85 - Flushed: 0 insertions, 0 updates, 0 deletions to 6 objects
22:05:20,921 DEBUG AbstractFlushingEventListener:91 - Flushed: 0 (re)creations, 1 updates, 0 removals to 1 collections
22:05:20,921 DEBUG Printer:83 - listing entities:
22:05:20,921 DEBUG Printer:90 - test.ManyToMany.Item{itemID=5, name=Item5}
22:05:20,921 DEBUG Printer:90 - test.ManyToMany.Item{itemID=3, name=Item3}
22:05:20,921 DEBUG Printer:90 - test.ManyToMany.Category{items=[test.ManyToMany.Item#2, test.ManyToMany.Item#3, test.ManyToMany.Item#4, test.ManyToMany.Item#5], categoryID=1, name=Test Category}
22:05:20,921 DEBUG Printer:90 - test.ManyToMany.Item{itemID=2, name=Item2}
22:05:20,921 DEBUG Printer:90 - test.ManyToMany.Item{itemID=4, name=Item4}
22:05:20,921 DEBUG Printer:90 - test.ManyToMany.Item{itemID=1, name=Item1}
22:05:20,921 DEBUG AbstractFlushingEventListener:289 - executing flush
22:05:20,921 DEBUG ConnectionManager:463 - registering flush begin
22:05:20,921 DEBUG AbstractCollectionPersister:1079 - Deleting rows of collection: [test.ManyToMany.Category.items#1]
22:05:20,921 DEBUG AbstractBatcher:311 - about to open PreparedStatement (open PreparedStatements: 0, globally: 0)


HERE IT DELETES THE 5 ROWS...


22:05:20,921 DEBUG SQL:346 - delete from CATEGORY_ITEM where CATEGORY_ITEMID=?
Hibernate: delete from CATEGORY_ITEM where CATEGORY_ITEMID=?
22:05:20,921 DEBUG AbstractBatcher:424 - preparing statement
22:05:20,937 DEBUG LongType:80 - binding '1' to parameter: 1
22:05:20,937 DEBUG AbstractBatcher:28 - Adding to batch
22:05:20,937 DEBUG LongType:80 - binding '2' to parameter: 1
22:05:20,937 DEBUG AbstractBatcher:28 - Adding to batch
22:05:20,937 DEBUG LongType:80 - binding '4' to parameter: 1
22:05:20,937 DEBUG AbstractBatcher:28 - Adding to batch
22:05:20,937 DEBUG LongType:80 - binding '3' to parameter: 1
22:05:20,937 DEBUG AbstractBatcher:28 - Adding to batch
22:05:20,937 DEBUG LongType:80 - binding '5' to parameter: 1
22:05:20,937 DEBUG AbstractBatcher:28 - Adding to batch
22:05:20,937 DEBUG AbstractCollectionPersister:1133 - done deleting collection rows: 5 deleted
22:05:20,937 DEBUG AbstractCollectionPersister:1333 - Updating rows of collection: test.ManyToMany.Category.items#1
22:05:20,937 DEBUG AbstractCollectionPersister:1340 - done updating rows: 0 updated
22:05:20,937 DEBUG AbstractCollectionPersister:1161 - Inserting rows of collection: [test.ManyToMany.Category.items#1]
22:05:20,937 DEBUG IncrementGenerator:80 - fetching initial value: select max(CATEGORY_ITEMID) from CATEGORY_ITEM
22:05:20,937 DEBUG AbstractBatcher:311 - about to open PreparedStatement (open PreparedStatements: 1, globally: 1)
22:05:20,937 DEBUG SQL:346 - select max(CATEGORY_ITEMID) from CATEGORY_ITEM
Hibernate: select max(CATEGORY_ITEMID) from CATEGORY_ITEM
22:05:20,937 DEBUG AbstractBatcher:424 - preparing statement
22:05:20,937 DEBUG IncrementGenerator:95 - first free id: 6
22:05:20,937 DEBUG AbstractBatcher:319 - about to close PreparedStatement (open PreparedStatements: 2, globally: 2)
22:05:20,937 DEBUG AbstractBatcher:470 - closing statement
22:05:20,937 DEBUG AbstractBatcher:55 - Executing batch size: 5
22:05:20,937 DEBUG AbstractBatcher:319 - about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
22:05:20,937 DEBUG AbstractBatcher:470 - closing statement
22:05:20,937 DEBUG AbstractBatcher:311 - about to open PreparedStatement (open PreparedStatements: 0, globally: 0)


...AND THEN REINSERTS THE 4 ROWS...


22:05:20,937 DEBUG SQL:346 - insert into CATEGORY_ITEM (CATEGORYID, CATEGORY_ITEMID, ITEMID) values (?, ?, ?)
Hibernate: insert into CATEGORY_ITEM (CATEGORYID, CATEGORY_ITEMID, ITEMID) values (?, ?, ?)
22:05:20,953 DEBUG AbstractBatcher:424 - preparing statement
22:05:20,953 DEBUG LongType:80 - binding '1' to parameter: 1
22:05:20,953 DEBUG LongType:80 - binding '6' to parameter: 2
22:05:20,953 DEBUG LongType:80 - binding '2' to parameter: 3
22:05:20,953 DEBUG AbstractBatcher:28 - Adding to batch
22:05:20,953 DEBUG AbstractBatcher:175 - reusing prepared statement
22:05:20,953 DEBUG SQL:346 - insert into CATEGORY_ITEM (CATEGORYID, CATEGORY_ITEMID, ITEMID) values (?, ?, ?)
Hibernate: insert into CATEGORY_ITEM (CATEGORYID, CATEGORY_ITEMID, ITEMID) values (?, ?, ?)
22:05:20,953 DEBUG LongType:80 - binding '1' to parameter: 1
22:05:20,953 DEBUG LongType:80 - binding '7' to parameter: 2
22:05:20,953 DEBUG LongType:80 - binding '3' to parameter: 3
22:05:20,953 DEBUG AbstractBatcher:28 - Adding to batch
22:05:20,953 DEBUG AbstractBatcher:175 - reusing prepared statement
22:05:20,953 DEBUG SQL:346 - insert into CATEGORY_ITEM (CATEGORYID, CATEGORY_ITEMID, ITEMID) values (?, ?, ?)
Hibernate: insert into CATEGORY_ITEM (CATEGORYID, CATEGORY_ITEMID, ITEMID) values (?, ?, ?)
22:05:20,953 DEBUG LongType:80 - binding '1' to parameter: 1
22:05:20,953 DEBUG LongType:80 - binding '8' to parameter: 2
22:05:20,953 DEBUG LongType:80 - binding '4' to parameter: 3
22:05:20,953 DEBUG AbstractBatcher:28 - Adding to batch
22:05:20,953 DEBUG AbstractBatcher:175 - reusing prepared statement
22:05:20,953 DEBUG SQL:346 - insert into CATEGORY_ITEM (CATEGORYID, CATEGORY_ITEMID, ITEMID) values (?, ?, ?)
Hibernate: insert into CATEGORY_ITEM (CATEGORYID, CATEGORY_ITEMID, ITEMID) values (?, ?, ?)
22:05:20,953 DEBUG LongType:80 - bi

_________________
"Man's Ego is the fountainhead of Human progress..."
(Ayn Rand)

Top
 Profile  
 
equality72521
 Post subject:
PostPosted: Tue Jun 06, 2006 8:08 pm 
Newbie

Joined: Fri Jun 02, 2006 9:31 pm
Posts: 7
UPDATE:
I figured out that this problem has nothing to do with the mapping or the database, but how I used MERGE.
So, the answer to this question is 50% "RTFM" and 50% "TFM is a little unclear..."

I found that updating an existing Item in the idbag or deleting an Item caused the entire collection to get deleted and re-inserted. Inserts of new transient Items failed completely (since the Item doesn't have a persistent identifier at the time of the merge). It was the same case for both a persistent idbag or a detached (and re-attached) idbag.

Changing
Code:
session.merge(category)
to
Code:
session.saveOrUpdate(category)
is a different story. saveOrUpdate only updated dirty Items and only deleted the Item relationships from the database that were removed from the collection. It did this without deleting and re-inserting. It also properly insert a new transient Item, then used its new persistent identifier to create the proper relationship in the database.

The moral of this story I think is: Don't use merge unless you have a very specific need for it.

So for my own education I'm hoping someone can explain to me what that specific need would be... Referring to pg 117 of the Reference Docs: I'm assuming that the category and its idbag of Items are already in session at the time of the merge (it says as much in the trace: "ignoring persistent instance", and "object already associated with session: [test.ManyToMany.Item#2]")
So is hibernate trying to copy the state
of the Category onto the persistent instance, or is it trying to create a new instance? Why does hibernate think it needs to delete/re-insert the relationships on a merge but not a saveOrUpdate?

Thanks

_________________
"Man's Ego is the fountainhead of Human progress..."
(Ayn Rand)

Top
 Profile  
 
Display posts from previous:  Sort by  
Forum locked This topic is locked, you cannot edit posts or make further replies.  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

Search for:
© Copyright 2014, Red Hat Inc. All rights reserved. JBoss and Hibernate are registered trademarks and servicemarks of Red Hat, Inc.