I'm having a problem with eager fetch and scroll. In documentation, it says that the fetch construct may not be used in queries called using iterate() (though scroll() can be used). I have items and their properties and I would like to eager fetch properties. I'm using scroll because the result set may be big. I get the first item with properties all initialized correctly. But I get only 1 property in the remaining items. I also tested with Hibernate 3.3, but got the same result. Any help would be appreciated. Thanks!
Hibernate version:
3.2.6
Mapping documents:
ItemTest.hbm.xml
<hibernate-mapping>
<class name="ItemTest" table="item_test">
<id name="id" column="item_test_id">
<generator class="native" />
</id>
<property name="name" column="name"/>
<set name="properties" table="item_test_property">
<key column="item_test_id" not-null="true"></key>
<element type="string" column="property" not-null="true"/>
</set>
</class>
</hibernate-mapping>
ItemTest.java
public class ItemTest {
private Integer id;
private String name;
private Set<String> properties;
public ItemTest() {
this.properties = new HashSet<String>();
}
/**
* @return the id
*/
public Integer getId() {
return id;
}
/**
* @param id the id to set
*/
public void setId(Integer id) {
this.id = id;
}
/**
* @return the name
*/
public String getName() {
return name;
}
/**
* @param name the name to set
*/
public void setName(String name) {
this.name = name;
}
/**
* @return the properties
*/
public Set<String> getProperties() {
return properties;
}
/**
* @param properties the properties to set
*/
public void setProperties(Set<String> properties) {
this.properties = properties;
}
public static void main (String [] args) {
Session session = null;
ItemTest itemTest = null;
Set<String> props = null;
Query q = null;
ScrollableResults results = null;
try {
session = HibernateUtil.getSessionFactory().getCurrentSession();
session.beginTransaction();
itemTest = new ItemTest();
props = new HashSet<String>();
props.add("prop1");
props.add("prop2");
props.add("prop3");
itemTest.setName("A");
itemTest.setProperties(props);
session.save(itemTest);
itemTest = new ItemTest();
props = new HashSet<String>();
props.add("prop4");
props.add("prop5");
props.add("prop6");
itemTest.setName("B");
itemTest.setProperties(props);
session.save(itemTest);
itemTest = new ItemTest();
props = new HashSet<String>();
props.add("prop7");
props.add("prop8");
props.add("prop9");
itemTest.setName("C");
itemTest.setProperties(props);
session.save(itemTest);
session.getTransaction().commit();
session = HibernateUtil.getSessionFactory().getCurrentSession();
session.beginTransaction();
q = session.createQuery("select it from ItemTest it left join fetch it.properties");
q.setCacheMode(CacheMode.IGNORE);
results = q.scroll(ScrollMode.FORWARD_ONLY);
while(results.next()) {
ItemTest it = (ItemTest)results.get(0);
System.out.println(it.name);
for(String prop : it.properties) {
System.out.println(prop);
}
System.out.println("==============");
}
results.close();
session.getTransaction().commit();
} catch (HibernateException h) {
session.getTransaction().rollback();
}
}
}
MySQL
CREATE TABLE item_test (
item_test_id INTEGER NOT NULL AUTO_INCREMENT,
name VARCHAR(512) NOT NULL,
PRIMARY KEY (item_test_id)
) CHARSET utf8;
CREATE TABLE item_test_property (
item_test_id INTEGER NOT NULL,
property VARCHAR(512) NOT NULL,
FOREIGN KEY (item_test_id) REFERENCES item_test (item_test_id)
) CHARSET utf8;
Hibernate.cfg.xml
<hibernate-configuration>
<session-factory>
<!-- You need to complete the configuration here. This is just a sample, you should use a connection pool -->
<property name="connection.url">jdbc:mysql://10.0.1.72/production?characterEncoding=UTF-8</property>
<property name="connection.username">producer</property>
<property name="connection.driver_class">com.mysql.jdbc.Driver</property>
<!-- Your database is MySQL-->
<property name="dialect">org.hibernate.dialect.MySQLDialect</property>
<property name="connection.password">xxx</property>
<property name="show_sql">true</property>
<property name="connection.autocommit">false</property>
<property name="hibernate.transaction.factory_class">org.hibernate.transaction.JDBCTransactionFactory</property>
<property name="hibernate.current_session_context_class">thread</property>
<property name="hibernate.transaction.flush_before_completion">true</property>
<property name="hibernate.transaction.auto_close_session">true</property>
<property name="hibernate.max_fetch_depth">3</property>
<property name="hibernate.jdbc.batch_size">20</property>
<property name="hibernate.cache.use_second_level_cache">false</property>
<property name="hibernate.default_batch_fetch_size">16</property>
<property name="hibernate.order_updates">true</property>
<property name="hibernate.generate_statistics">true</property>
<property name="hibernate.c3p0.min_size">5</property>
<property name="hibernate.c3p0.max_size">20</property>
<property name="hibernate.c3p0.timeout">1800</property>
<property name="hibernate.c3p0.max_statements">50</property>
<mapping resource="ItemTest.hbm.xml" />
</session-factory>
</hibernate-configuration>
Code between sessionFactory.openSession() and session.close():
see main method in ItemTest.java
output from the code:
A
prop3
prop1
prop2
==============
B
prop4
==============
C
prop9
==============
Full stack trace of any exception that occurs:
none
Name and version of the database you are using:
MySQL 5.0.45
The generated SQL (show_sql=true):
Hibernate: insert into item_test (name) values (?)
Hibernate: insert into item_test (name) values (?)
Hibernate: insert into item_test (name) values (?)
Hibernate: insert into item_test_property (item_test_id, property) values (?, ?)
Hibernate: insert into item_test_property (item_test_id, property) values (?, ?)
Hibernate: insert into item_test_property (item_test_id, property) values (?, ?)
Hibernate: insert into item_test_property (item_test_id, property) values (?, ?)
Hibernate: insert into item_test_property (item_test_id, property) values (?, ?)
Hibernate: insert into item_test_property (item_test_id, property) values (?, ?)
Hibernate: insert into item_test_property (item_test_id, property) values (?, ?)
Hibernate: insert into item_test_property (item_test_id, property) values (?, ?)
Hibernate: insert into item_test_property (item_test_id, property) values (?, ?)
Hibernate: select itemtest0_.item_test_id as item1_0_, itemtest0_.name as name0_, properties1_.item_test_id as item1_0__, properties1_.property as property0__ from item_test itemtest0_ left outer join item_test_property properties1_ on itemtest0_.item_test_id=properties1_.item_test_id
Debug level Hibernate log excerpt:
14:38:58,437 INFO Environment:514 - Hibernate 3.2.6
14:38:58,453 INFO Environment:547 - hibernate.properties not found
14:38:58,453 INFO Environment:681 - Bytecode provider name : cglib
14:38:58,468 INFO Environment:598 - using JDK 1.4 java.sql.Timestamp handling
14:38:58,578 INFO Configuration:1432 - configuring from resource: /hibernate.cfg.xml
14:38:58,578 INFO Configuration:1409 - Configuration resource: /hibernate.cfg.xml
14:38:58,687 DEBUG DTDEntityResolver:38 - trying to resolve system-id [http://hibernate.sourceforge.net/hibernate-configuration-3.0.dtd]
14:38:58,703 DEBUG DTDEntityResolver:40 - recognized hibernate namespace; attempting to resolve on classpath under org/hibernate/
14:38:58,703 DEBUG DTDEntityResolver:50 - located [http://hibernate.sourceforge.net/hibernate-configuration-3.0.dtd] in classpath
14:38:58,765 DEBUG Configuration:1393 - connection.url=jdbc:mysql://10.0.1.72/production?characterEncoding=UTF-8
14:38:58,765 DEBUG Configuration:1393 - connection.username=producer
14:38:58,765 DEBUG Configuration:1393 - connection.driver_class=com.mysql.jdbc.Driver
14:38:58,765 DEBUG Configuration:1393 - dialect=org.hibernate.dialect.MySQLDialect
14:38:58,765 DEBUG Configuration:1393 - connection.password=xxx
14:38:58,765 DEBUG Configuration:1393 - show_sql=true
14:38:58,765 DEBUG Configuration:1393 - connection.autocommit=false
14:38:58,765 DEBUG Configuration:1393 - hibernate.transaction.factory_class=org.hibernate.transaction.JDBCTransactionFactory
14:38:58,765 DEBUG Configuration:1393 - hibernate.current_session_context_class=thread
14:38:58,781 DEBUG Configuration:1393 - hibernate.transaction.flush_before_completion=true
14:38:58,781 DEBUG Configuration:1393 - hibernate.transaction.auto_close_session=true
14:38:58,781 DEBUG Configuration:1393 - hibernate.max_fetch_depth=3
14:38:58,781 DEBUG Configuration:1393 - hibernate.jdbc.batch_size=20
14:38:58,781 DEBUG Configuration:1393 - hibernate.cache.use_second_level_cache=false
14:38:58,781 DEBUG Configuration:1393 - hibernate.default_batch_fetch_size=16
14:38:58,781 DEBUG Configuration:1393 - hibernate.order_updates=true
14:38:58,781 DEBUG Configuration:1393 - hibernate.generate_statistics=true
14:38:58,781 DEBUG Configuration:1393 - hibernate.c3p0.min_size=5
14:38:58,781 DEBUG Configuration:1393 - hibernate.c3p0.max_size=20
14:38:58,781 DEBUG Configuration:1393 - hibernate.c3p0.timeout=1800
14:38:58,781 DEBUG Configuration:1393 - hibernate.c3p0.max_statements=50
14:38:58,781 DEBUG Configuration:1592 - null<-org.dom4j.tree.DefaultAttribute@1c9e67a [Attribute: name resource value "ItemTest.hbm.xml"]
14:38:58,796 INFO Configuration:559 - Reading mappings from resource : ItemTest.hbm.xml
14:38:58,796 DEBUG DTDEntityResolver:38 - trying to resolve system-id [http://hibernate.sourceforge.net/hibernate-mapping-3.0.dtd]
14:38:58,796 DEBUG DTDEntityResolver:40 - recognized hibernate namespace; attempting to resolve on classpath under org/hibernate/
14:38:58,796 DEBUG DTDEntityResolver:50 - located [http://hibernate.sourceforge.net/hibernate-mapping-3.0.dtd] in classpath
14:38:58,968 INFO HbmBinder:300 - Mapping class: com.cataphora.apps.production.test.item.ItemTest -> item_test
14:38:59,000 DEBUG HbmBinder:1267 - Mapped property: id -> item_test_id
14:38:59,015 DEBUG HbmBinder:1267 - Mapped property: name -> name
14:38:59,015 INFO HbmBinder:1419 - Mapping collection: com.cataphora.apps.production.test.item.ItemTest.properties -> item_test_property
14:38:59,015 DEBUG HbmBinder:1267 - Mapped property: properties
14:38:59,015 INFO Configuration:1547 - Configured SessionFactory: null
14:38:59,031 DEBUG Configuration:1548 - properties: {java.vendor=Sun Microsystems Inc., show_sql=true, sun.java.launcher=SUN_STANDARD, hibernate.connection.url=jdbc:mysql://10.0.1.72/production?characterEncoding=UTF-8, sun.management.compiler=HotSpot Client Compiler, hibernate.transaction.flush_before_completion=true, os.name=Windows 2000, sun.boot.class.path=C:\Program Files\Java\jdk1.5.0_11\jre\lib\rt.jar;C:\Program Files\Java\jdk1.5.0_11\jre\lib\i18n.jar;C:\Program Files\Java\jdk1.5.0_11\jre\lib\sunrsasign.jar;C:\Program Files\Java\jdk1.5.0_11\jre\lib\jsse.jar;C:\Program Files\Java\jdk1.5.0_11\jre\lib\jce.jar;C:\Program Files\Java\jdk1.5.0_11\jre\lib\charsets.jar;C:\Program Files\Java\jdk1.5.0_11\jre\classes, hibernate.current_session_context_class=thread, sun.desktop=windows, hibernate.c3p0.max_size=20, java.vm.specification.vendor=Sun Microsystems Inc., hibernate.generate_statistics=true, java.runtime.version=1.5.0_11-b03, hibernate.connection.autocommit=false, hibernate.c3p0.min_size=5, user.name=Administrator, connection.driver_class=com.mysql.jdbc.Driver, hibernate.c3p0.timeout=1800, user.language=en, sun.boot.library.path=C:\Program Files\Java\jdk1.5.0_11\jre\bin, dialect=org.hibernate.dialect.MySQLDialect, java.version=1.5.0_11, user.timezone=America/Los_Angeles, sun.arch.data.model=32, java.endorsed.dirs=C:\Program Files\Java\jdk1.5.0_11\jre\lib\endorsed, sun.cpu.isalist=, sun.jnu.encoding=Cp1252, file.encoding.pkg=sun.io, file.separator=\, java.specification.name=Java Platform API Specification, java.class.version=49.0, user.country=US, connection.url=jdbc:mysql://10.0.1.72/production?characterEncoding=UTF-8, java.home=C:\Program Files\Java\jdk1.5.0_11\jre, java.vm.info=mixed mode, os.version=5.0, hibernate.transaction.factory_class=org.hibernate.transaction.JDBCTransactionFactory, path.separator=;, connection.password=xxx, java.vm.version=1.5.0_11-b03, hibernate.max_fetch_depth=3, hibernate.connection.password=xxx, user.variant=, hibernate.jdbc.batch_size=20, java.awt.printerjob=sun.awt.windows.WPrinterJob, hibernate.order_updates=true, java.security.policy=policy.all, sun.io.unicode.encoding=UnicodeLittle, awt.toolkit=sun.awt.windows.WToolkit, hibernate.connection.username=producer, user.home=C:\Documents and Settings\Administrator, java.specification.vendor=Sun Microsystems Inc., java.library.path=C:\Program Files\Java\jdk1.5.0_11\bin;.;C:\WINNT\system32;C:\WINNT;C:\cygwin\bin;C:\Python22\.;C:\Perl\bin\;C:\WINNT\system32;C:\WINNT;C:\WINNT\System32\Wbem;C:\Program Files\Vshell\Bin;E:\CSL\bin;C:\Program Files\Intel\DMIX;C:\Program Files\lotus\notes;C:\Program Files\AMCC\CLI;c:\Program Files\MySQL\MySQL Server 5.0\bin;C:\Program Files\SSH Communications Security\SSH Secure Shell;C:\Program Files\Java\jdk1.5.0_11\bin, java.vendor.url=http://java.sun.com/, hibernate.connection.driver_class=com.mysql.jdbc.Driver, connection.username=producer, java.vm.vendor=Sun Microsystems Inc., hibernate.dialect=org.hibernate.dialect.MySQLDialect, java.runtime.name=Java(TM) 2 Runtime Environment, Standard Edition, java.class.path=.;bin\CEvidence.jar;bin\javacsv\javacsv.jar;bin\rmi\rmiio-2.0.0.jar;bin\log4j\log4j-1.2.13.jar;bin\berkeleydb\db.jar;bin\commons\commons-logging-1.1.jar;bin\lucene\lucene-1.4.3.jar;bin\javamail\mail.jar;bin\mysql\mysql-connector-java-3.1.8-bin.jar;bin\hibernate\hibernate3.jar;bin\hibernate\antlr-2.7.6.jar;bin\hibernate\asm.jar;bin\hibernate\asm-attrs.jar;bin\hibernate\cglib-2.1.3.jar;bin\hibernate\commons-collections-2.1.1.jar;bin\hibernate\dom4j-1.6.1.jar;bin\hibernate\ehcache-1.2.3.jar;bin\hibernate\jta.jar;bin\hibernate\c3p0-0.9.1.2.jar;xml;, hibernate.transaction.auto_close_session=true, hibernate.bytecode.use_reflection_optimizer=false, java.vm.specification.name=Java Virtual Machine Specification, java.vm.specification.version=1.0, sun.cpu.endian=little, sun.os.patch.level=Service Pack 4, java.rmi.server.codebase=file:/I:/bin/CEvidence.jar, connection.autocommit=false, java.io.tmpdir=c:\tmp\1\, java.vendor.url.bug=http://java.sun.com/cgi-bin/bugreport.cgi, os.arch=x86, java.awt.graphicsenv=sun.awt.Win32GraphicsEnvironment, java.ext.dirs=C:\Program Files\Java\jdk1.5.0_11\jre\lib\ext, user.dir=I:\, line.separator=
, java.vm.name=Java HotSpot(TM) Client VM, hibernate.default_batch_fetch_size=16, hibernate.cache.use_second_level_cache=false, file.encoding=Cp1252, java.specification.version=1.5, hibernate.c3p0.max_statements=50, hibernate.show_sql=true}
14:38:59,031 DEBUG Configuration:1291 - Preparing to build session factory with filters : {}
14:38:59,031 DEBUG Configuration:1126 - processing extends queue
14:38:59,031 DEBUG Configuration:1130 - processing collection mappings
14:38:59,031 DEBUG CollectionSecondPass:41 - Second pass for collection: com.cataphora.apps.production.test.item.ItemTest.properties
14:38:59,031 DEBUG CollectionSecondPass:57 - Mapped collection key: item_test_id, element: property
14:38:59,031 DEBUG Configuration:1141 - processing native query and ResultSetMapping mappings
14:38:59,031 DEBUG Configuration:1149 - processing association property references
14:38:59,031 DEBUG Configuration:1171 - processing foreign key constraints
14:38:59,031 DEBUG Configuration:1254 - resolving reference to class: com.cataphora.apps.production.test.item.ItemTest
14:38:59,156 INFO C3P0ConnectionProvider:81 - C3P0 using driver: com.mysql.jdbc.Driver at URL: jdbc:mysql://10.0.1.72/production?characterEncoding=UTF-8
14:38:59,171 INFO C3P0ConnectionProvider:82 - Connection properties: {user=producer, password=****, autocommit=false}
14:38:59,171 INFO C3P0ConnectionProvider:85 - autocommit mode: false
14:39:00,281 INFO SettingsFactory:89 - RDBMS: MySQL, version: 5.0.45-community-nt
14:39:00,281 INFO SettingsFactory:90 - JDBC driver: MySQL-AB JDBC Driver, version: mysql-connector-java-3.1.8 ( $Date: 2005/04/14 20:36:13 $, $Revision: 1.27.4.64 $ )
14:39:00,343 INFO Dialect:152 - Using dialect: org.hibernate.dialect.MySQLDialect
14:39:00,343 INFO TransactionFactoryFactory:34 - Transaction strategy: org.hibernate.transaction.JDBCTransactionFactory
14:39:00,359 INFO TransactionManagerLookupFactory:33 - No TransactionManagerLookup configured (in JTA environment, use of read-write or transactional second-level cache is not recommended)
14:39:00,359 INFO SettingsFactory:143 - Automatic flush during beforeCompletion(): enabled
14:39:00,359 INFO SettingsFactory:147 - Automatic session close at end of transaction: enabled
14:39:00,359 INFO SettingsFactory:154 - JDBC batch size: 20
14:39:00,359 INFO SettingsFactory:157 - JDBC batch updates for versioned data: disabled
14:39:00,359 INFO SettingsFactory:162 - Scrollable result sets: enabled
14:39:00,359 DEBUG SettingsFactory:166 - Wrap result sets: disabled
14:39:00,359 INFO SettingsFactory:170 - JDBC3 getGeneratedKeys(): enabled
14:39:00,359 INFO SettingsFactory:178 - Connection release mode: auto
14:39:00,375 INFO SettingsFactory:202 - Maximum outer join fetch depth: 3
14:39:00,375 INFO SettingsFactory:205 - Default batch fetch size: 16
14:39:00,375 INFO SettingsFactory:209 - Generate SQL with comments: disabled
14:39:00,375 INFO SettingsFactory:213 - Order SQL updates by primary key: enabled
14:39:00,375 INFO SettingsFactory:217 - Order SQL inserts for batching: disabled
14:39:00,375 INFO SettingsFactory:386 - Query translator: org.hibernate.hql.ast.ASTQueryTranslatorFactory
14:39:00,375 INFO ASTQueryTranslatorFactory:24 - Using ASTQueryTranslatorFactory
14:39:00,375 INFO SettingsFactory:225 - Query language substitutions: {}
14:39:00,375 INFO SettingsFactory:230 - JPA-QL strict compliance: disabled
14:39:00,390 INFO SettingsFactory:235 - Second-level cache: disabled
14:39:00,390 INFO SettingsFactory:239 - Query cache: disabled
14:39:00,390 INFO SettingsFactory:254 - Optimize cache for minimal puts: disabled
14:39:00,390 INFO SettingsFactory:263 - Structured second-level cache entries: disabled
14:39:00,406 INFO SettingsFactory:283 - Echoing all SQL to stdout
14:39:00,406 INFO SettingsFactory:290 - Statistics: enabled
14:39:00,406 INFO SettingsFactory:294 - Deleted entity synthetic identifier rollback: disabled
14:39:00,406 INFO SettingsFactory:309 - Default entity-mode: pojo
14:39:00,406 INFO SettingsFactory:313 - Named query checking : enabled
14:39:00,468 INFO SessionFactoryImpl:161 - building session factory
14:39:00,468 DEBUG SessionFactoryImpl:173 - Session factory constructed with filter configurations : {}
14:39:00,468 DEBUG SessionFactoryImpl:177 - instantiating session factory with properties: {java.vendor=Sun Microsystems Inc., show_sql=true, sun.java.launcher=SUN_STANDARD, hibernate.connection.url=jdbc:mysql://10.0.1.72/production?characterEncoding=UTF-8, sun.management.compiler=HotSpot Client Compiler, hibernate.transaction.flush_before_completion=true, os.name=Windows 2000, sun.boot.class.path=C:\Program Files\Java\jdk1.5.0_11\jre\lib\rt.jar;C:\Program Files\Java\jdk1.5.0_11\jre\lib\i18n.jar;C:\Program Files\Java\jdk1.5.0_11\jre\lib\sunrsasign.jar;C:\Program Files\Java\jdk1.5.0_11\jre\lib\jsse.jar;C:\Program Files\Java\jdk1.5.0_11\jre\lib\jce.jar;C:\Program Files\Java\jdk1.5.0_11\jre\lib\charsets.jar;C:\Program Files\Java\jdk1.5.0_11\jre\classes, hibernate.current_session_context_class=thread, sun.desktop=windows, hibernate.c3p0.max_size=20, java.vm.specification.vendor=Sun Microsystems Inc., hibernate.generate_statistics=true, java.runtime.version=1.5.0_11-b03, hibernate.connection.autocommit=false, hibernate.c3p0.min_size=5, user.name=Administrator, connection.driver_class=com.mysql.jdbc.Driver, hibernate.c3p0.timeout=1800, user.language=en, sun.boot.library.path=C:\Program Files\Java\jdk1.5.0_11\jre\bin, dialect=org.hibernate.dialect.MySQLDialect, java.version=1.5.0_11, user.timezone=America/Los_Angeles, sun.arch.data.model=32, java.endorsed.dirs=C:\Program Files\Java\jdk1.5.0_11\jre\lib\endorsed, sun.cpu.isalist=, sun.jnu.encoding=Cp1252, file.encoding.pkg=sun.io, file.separator=\, java.specification.name=Java Platform API Specification, java.class.version=49.0, user.country=US, connection.url=jdbc:mysql://10.0.1.72/production?characterEncoding=UTF-8, java.home=C:\Program Files\Java\jdk1.5.0_11\jre, java.vm.info=mixed mode, os.version=5.0, hibernate.transaction.factory_class=org.hibernate.transaction.JDBCTransactionFactory, path.separator=;, connection.password=xxx, java.vm.version=1.5.0_11-b03, hibernate.max_fetch_depth=3, hibernate.connection.password=xxx, user.variant=, hibernate.jdbc.batch_size=20, java.awt.printerjob=sun.awt.windows.WPrinterJob, java.security.policy=policy.all, hibernate.order_updates=true, sun.io.unicode.encoding=UnicodeLittle, awt.toolkit=sun.awt.windows.WToolkit, hibernate.connection.username=producer, user.home=C:\Documents and Settings\Administrator, java.specification.vendor=Sun Microsystems Inc., java.library.path=C:\Program Files\Java\jdk1.5.0_11\bin;.;C:\WINNT\system32;C:\WINNT;C:\cygwin\bin;C:\Python22\.;C:\Perl\bin\;C:\WINNT\system32;C:\WINNT;C:\WINNT\System32\Wbem;C:\Program Files\Vshell\Bin;E:\CSL\bin;C:\Program Files\Intel\DMIX;C:\Program Files\lotus\notes;C:\Program Files\AMCC\CLI;c:\Program Files\MySQL\MySQL Server 5.0\bin;C:\Program Files\SSH Communications Security\SSH Secure Shell;C:\Program Files\Java\jdk1.5.0_11\bin, java.vendor.url=http://java.sun.com/, hibernate.connection.driver_class=com.mysql.jdbc.Driver, connection.username=producer, java.vm.vendor=Sun Microsystems Inc., hibernate.dialect=org.hibernate.dialect.MySQLDialect, java.runtime.name=Java(TM) 2 Runtime Environment, Standard Edition, java.class.path=.;bin\CEvidence.jar;bin\javacsv\javacsv.jar;bin\rmi\rmiio-2.0.0.jar;bin\log4j\log4j-1.2.13.jar;bin\berkeleydb\db.jar;bin\commons\commons-logging-1.1.jar;bin\lucene\lucene-1.4.3.jar;bin\javamail\mail.jar;bin\mysql\mysql-connector-java-3.1.8-bin.jar;bin\hibernate\hibernate3.jar;bin\hibernate\antlr-2.7.6.jar;bin\hibernate\asm.jar;bin\hibernate\asm-attrs.jar;bin\hibernate\cglib-2.1.3.jar;bin\hibernate\commons-collections-2.1.1.jar;bin\hibernate\dom4j-1.6.1.jar;bin\hibernate\ehcache-1.2.3.jar;bin\hibernate\jta.jar;bin\hibernate\c3p0-0.9.1.2.jar;xml;, hibernate.transaction.auto_close_session=true, hibernate.bytecode.use_reflection_optimizer=false, java.vm.specification.name=Java Virtual Machine Specification, java.vm.specification.version=1.0, sun.cpu.endian=little, sun.os.patch.level=Service Pack 4, java.rmi.server.codebase=file:/I:/bin/CEvidence.jar, connection.autocommit=false, java.io.tmpdir=c:\tmp\1\, java.vendor.url.bug=http://java.sun.com/cgi-bin/bugreport.cgi, java.awt.graphicsenv=sun.awt.Win32GraphicsEnvironment, os.arch=x86, java.ext.dirs=C:\Program Files\Java\jdk1.5.0_11\jre\lib\ext, user.dir=I:\, line.separator=
, java.vm.name=Java HotSpot(TM) Client VM, hibernate.default_batch_fetch_size=16, hibernate.cache.use_second_level_cache=false, file.encoding=Cp1252, java.specification.version=1.5, hibernate.show_sql=true, hibernate.c3p0.max_statements=50}
14:39:00,968 DEBUG AbstractEntityPersister:2743 - Static SQL for entity: com.cataphora.apps.production.test.item.ItemTest
14:39:00,968 DEBUG AbstractEntityPersister:2748 - Version select: select item_test_id from item_test where item_test_id =?
14:39:00,968 DEBUG AbstractEntityPersister:2751 - Snapshot select: select itemtest_.item_test_id, itemtest_.name as name0_ from item_test itemtest_ where itemtest_.item_test_id=?
14:39:00,968 DEBUG AbstractEntityPersister:2754 - Insert 0: insert into item_test (name, item_test_id) values (?, ?)
14:39:00,968 DEBUG AbstractEntityPersister:2755 - Update 0: update item_test set name=? where item_test_id=?
14:39:00,968 DEBUG AbstractEntityPersister:2756 - Delete 0: delete from item_test where item_test_id=?
14:39:00,968 DEBUG AbstractEntityPersister:2760 - Identity insert: insert into item_test (name) values (?)
14:39:01,000 DEBUG AbstractCollectionPersister:548 - Static SQL for collection: com.cataphora.apps.production.test.item.ItemTest.properties
14:39:01,000 DEBUG AbstractCollectionPersister:550 - Row insert: insert into item_test_property (item_test_id, property) values (?, ?)
14:39:01,000 DEBUG AbstractCollectionPersister:553 - Row update: update item_test_property set property=? where item_test_id=? and property=?
14:39:01,000 DEBUG AbstractCollectionPersister:556 - Row delete: delete from item_test_property where item_test_id=? and property=?
14:39:01,000 DEBUG AbstractCollectionPersister:559 - One-shot delete: delete from item_test_property where item_test_id=?
14:39:01,046 DEBUG EntityLoader:79 - Static select for entity com.cataphora.apps.production.test.item.ItemTest: select itemtest0_.item_test_id as item1_0_0_, itemtest0_.name as name0_0_ from item_test itemtest0_ where itemtest0_.item_test_id in (?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?)
14:39:01,046 DEBUG EntityLoader:79 - Static select for entity com.cataphora.apps.production.test.item.ItemTest: select itemtest0_.item_test_id as item1_0_0_, itemtest0_.name as name0_0_ from item_test itemtest0_ where itemtest0_.item_test_id in (?, ?, ?, ?, ?, ?, ?, ?, ?, ?)
14:39:01,046 DEBUG EntityLoader:79 - Static select for entity com.cataphora.apps.production.test.item.ItemTest: select itemtest0_.item_test_id as item1_0_0_, itemtest0_.name as name0_0_ from item_test itemtest0_ where itemtest0_.item_test_id in (?, ?, ?, ?, ?, ?, ?, ?, ?)
14:39:01,046 DEBUG EntityLoader:79 - Static select for entity com.cataphora.apps.production.test.item.ItemTest: select itemtest0_.item_test_id as item1_0_0_, itemtest0_.name as name0_0_ from item_test itemtest0_ where itemtest0_.item_test_id in (?, ?, ?, ?, ?, ?, ?, ?)
14:39:01,046 DEBUG EntityLoader:79 - Static select for entity com.cataphora.apps.production.test.item.ItemTest: select itemtest0_.item_test_id as item1_0_0_, itemtest0_.name as name0_0_ from item_test itemtest0_ where itemtest0_.item_test_id in (?, ?, ?, ?, ?, ?, ?)
14:39:01,046 DEBUG EntityLoader:79 - Static select for entity com.cataphora.apps.production.test.item.ItemTest: select itemtest0_.item_test_id as item1_0_0_, itemtest0_.name as name0_0_ from item_test itemtest0_ where itemtest0_.item_test_id in (?, ?, ?, ?, ?, ?)
14:39:01,046 DEBUG EntityLoader:79 - Static select for entity com.cataphora.apps.production.test.item.ItemTest: select itemtest0_.item_test_id as item1_0_0_, itemtest0_.name as name0_0_ from item_test itemtest0_ where itemtest0_.item_test_id in (?, ?, ?, ?, ?)
14:39:01,046 DEBUG EntityLoader:79 - Static select for entity com.cataphora.apps.production.test.item.ItemTest: select itemtest0_.item_test_id as item1_0_0_, itemtest0_.name as name0_0_ from item_test itemtest0_ where itemtest0_.item_test_id in (?, ?, ?, ?)
14:39:01,046 DEBUG EntityLoader:79 - Static select for entity com.cataphora.apps.production.test.item.ItemTest: select itemtest0_.item_test_id as item1_0_0_, itemtest0_.name as name0_0_ from item_test itemtest0_ where itemtest0_.item_test_id in (?, ?, ?)
14:39:01,046 DEBUG EntityLoader:79 - Static select for entity com.cataphora.apps.production.test.item.ItemTest: select itemtest0_.item_test_id as item1_0_0_, itemtest0_.name as name0_0_ from item_test itemtest0_ where itemtest0_.item_test_id in (?, ?)
14:39:01,046 DEBUG EntityLoader:79 - Static select for entity com.cataphora.apps.production.test.item.ItemTest: select itemtest0_.item_test_id as item1_0_0_, itemtest0_.name as name0_0_ from item_test itemtest0_ where itemtest0_.item_test_id=?
14:39:01,046 DEBUG EntityLoader:79 - Static select for entity com.cataphora.apps.production.test.item.ItemTest: select itemtest0_.item_test_id as item1_0_0_, itemtest0_.name as name0_0_ from item_test itemtest0_ where itemtest0_.item_test_id in (?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?)
14:39:01,046 DEBUG EntityLoader:79 - Static select for entity com.cataphora.apps.production.test.item.ItemTest: select itemtest0_.item_test_id as item1_0_0_, itemtest0_.name as name0_0_ from item_test itemtest0_ where itemtest0_.item_test_id in (?, ?, ?, ?, ?, ?, ?, ?, ?, ?)
14:39:01,046 DEBUG EntityLoader:79 - Static select for entity com.cataphora.apps.production.test.item.ItemTest: select itemtest0_.item_test_id as item1_0_0_, itemtest0_.name as name0_0_ from item_test itemtest0_ where itemtest0_.item_test_id in (?, ?, ?, ?, ?, ?, ?, ?, ?)
14:39:01,046 DEBUG EntityLoader:79 - Static select for entity com.cataphora.apps.production.test.item.ItemTest: select itemtest0_.item_test_id as item1_0_0_, itemtest0_.name as name0_0_ from item_test itemtest0_ where itemtest0_.item_test_id in (?, ?, ?, ?, ?, ?, ?, ?)
14:39:01,062 DEBUG EntityLoader:79 - Static select for entity com.cataphora.apps.production.test.item.ItemTest: select itemtest0_.item_test_id as item1_0_0_, itemtest0_.name as name0_0_ from item_test itemtest0_ where itemtest0_.item_test_id in (?, ?, ?, ?, ?, ?, ?)
14:39:01,062 DEBUG EntityLoader:79 - Static select for entity com.cataphora.apps.production.test.item.ItemTest: select itemtest0_.item_test_id as item1_0_0_, itemtest0_.name as name0_0_ from item_test itemtest0_ where itemtest0_.item_test_id in (?, ?, ?, ?, ?, ?)
14:39:01,062 DEBUG EntityLoader:79 - Static select for entity com.cataphora.apps.production.test.item.ItemTest: select itemtest0_.item_test_id as item1_0_0_, itemtest0_.name as name0_0_ from item_test itemtest0_ where itemtest0_.item_test_id in (?, ?, ?, ?, ?)
14:39:01,062 DEBUG EntityLoader:79 - Static select for entity com.cataphora.apps.production.test.item.ItemTest: select itemtest0_.item_test_id as item1_0_0_, itemtest0_.name as name0_0_ from item_test itemtest0_ where itemtest0_.item_test_id in (?, ?, ?, ?)
14:39:01,062 DEBUG EntityLoader:79 - Static select for entity com.cataphora.apps.production.test.item.ItemTest: select itemtest0_.item_test_id as item1_0_0_, itemtest0_.name as name0_0_ from item_test itemtest0_ where itemtest0_.item_test_id in (?, ?, ?)
14:39:01,062 DEBUG EntityLoader:79 - Static select for entity com.cataphora.apps.production.test.item.ItemTest: select itemtest0_.item_test_id as item1_0_0_, itemtest0_.name as name0_0_ from item_test itemtest0_ where itemtest0_.item_test_id in (?, ?)
14:39:01,062 DEBUG EntityLoader:79 - Static select for entity com.cataphora.apps.production.test.item.ItemTest: select itemtest0_.item_test_id as item1_0_0_, itemtest0_.name as name0_0_ from item_test itemtest0_ where itemtest0_.item_test_id=?
14:39:01,062 DEBUG EntityLoader:79 - Static select for entity com.cataphora.apps.production.test.item.ItemTest: select itemtest0_.item_test_id as item1_0_0_, itemtest0_.name as name0_0_ from item_test itemtest0_ where itemtest0_.item_test_id in (?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?) for update
14:39:01,062 DEBUG EntityLoader:79 - Static select for entity com.cataphora.apps.production.test.item.ItemTest: select itemtest0_.item_test_id as item1_0_0_, itemtest0_.name as name0_0_ from item_test itemtest0_ where itemtest0_.item_test_id in (?, ?, ?, ?, ?, ?, ?, ?, ?, ?) for update
14:39:01,062 DEBUG EntityLoader:79 - Static select for entity com.cataphora.apps.production.test.item.ItemTest: select itemtest0_.item_test_id as item1_0_0_, itemtest0_.name as name0_0_ from item_test itemtest0_ where itemtest0_.item_test_id in (?, ?, ?, ?, ?, ?, ?, ?, ?) for update
14:39:01,062 DEBUG EntityLoader:79 - Static select for entity com.cataphora.apps.production.test.item.ItemTest: select itemtest0_.item_test_id as item1_0_0_, itemtest0_.name as name0_0_ from item_test itemtest0_ where itemtest0_.item_test_id in (?, ?, ?, ?, ?, ?, ?, ?) for update
14:39:01,062 DEBUG EntityLoader:79 - Static select for entity com.cataphora.apps.production.test.item.ItemTest: select itemtest0_.item_test_id as item1_0_0_, itemtest0_.name as name0_0_ from item_test itemtest0_ where itemtest0_.item_test_id in (?, ?, ?, ?, ?, ?, ?) for update
14:39:01,062 DEBUG EntityLoader:79 - Static select for entity com.cataphora.apps.production.test.item.ItemTest: select itemtest0_.item_test_id as item1_0_0_, itemtest0_.name as name0_0_ from item_test itemtest0_ where itemtest0_.item_test_id in (?, ?, ?, ?, ?, ?) for update
14:39:01,062 DEBUG EntityLoader:79 - Static select for entity com.cataphora.apps.production.test.item.ItemTest: select itemtest0_.item_test_id as item1_0_0_, itemtest0_.name as name0_0_ from item_test itemtest0_ where itemtest0_.item_test_id in (?, ?, ?, ?, ?) for update
14:39:01,062 DEBUG EntityLoader:79 - Static select for entity com.cataphora.apps.production.test.item.ItemTest: select itemtest0_.item_test_id as item1_0_0_, itemtest0_.name as name0_0_ from item_test itemtest0_ where itemtest0_.item_test_id in (?, ?, ?, ?) for update
14:39:01,062 DEBUG EntityLoader:79 - Static select for entity com.cataphora.apps.production.test.item.ItemTest: select itemtest0_.item_test_id as item1_0_0_, itemtest0_.name as name0_0_ from item_test itemtest0_ where itemtest0_.item_test_id in (?, ?, ?) for update
14:39:01,062 DEBUG EntityLoader:79 - Static select for entity com.cataphora.apps.production.test.item.ItemTest: select itemtest0_.item_test_id as item1_0_0_, itemtest0_.name as name0_0_ from item_test itemtest0_ where itemtest0_.item_test_id in (?, ?) for update
14:39:01,062 DEBUG EntityLoader:79 - Static select for entity com.cataphora.apps.production.test.item.ItemTest: select itemtest0_.item_test_id as item1_0_0_, itemtest0_.name as name0_0_ from item_test itemtest0_ where itemtest0_.item_test_id=? for update
14:39:01,062 DEBUG EntityLoader:79 - Static select for entity com.cataphora.apps.production.test.item.ItemTest: select itemtest0_.item_test_id as item1_0_0_, itemtest0_.name as name0_0_ from item_test itemtest0_ where itemtest0_.item_test_id in (?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?) for update
14:39:01,062 DEBUG EntityLoader:79 - Static select for entity com.cataphora.apps.production.test.item.ItemTest: select itemtest0_.item_test_id as item1_0_0_, itemtest0_.name as name0_0_ from item_test itemtest0_ where itemtest0_.item_test_id in (?, ?, ?, ?, ?, ?, ?, ?, ?, ?) for update
14:39:01,062 DEBUG EntityLoader:79 - Static select for entity com.cataphora.apps.production.test.item.ItemTest: select itemtest0_.item_test_id as item1_0_0_, itemtest0_.name as name0_0_ from item_test itemtest0_ where itemtest0_.item_test_id in (?, ?, ?, ?, ?, ?, ?, ?, ?) for update
14:39:01,062 DEBUG EntityLoader:79 - Static select for entity com.cataphora.apps.production.test.item.ItemTest: select itemtest0_.item_test_id as item1_0_0_, itemtest0_.name as name0_0_ from item_test itemtest0_ where itemtest0_.item_test_id in (?, ?, ?, ?, ?, ?, ?, ?) for update
14:39:01,078 DEBUG EntityLoader:79 - Static select for entity com.cataphora.apps.production.test.item.ItemTest: select itemtest0_.item_test_id as item1_0_0_, itemtest0_.name as name0_0_ from item_test itemtest0_ where itemtest0_.item_test_id in (?, ?, ?, ?, ?, ?, ?) for update
14:39:01,078 DEBUG EntityLoader:79 - Static select for entity com.cataphora.apps.production.test.item.ItemTest: select itemtest0_.item_test_id as item1_0_0_, itemtest0_.name as name0_0_ from item_test itemtest0_ where itemtest0_.item_test_id in (?, ?, ?, ?, ?, ?) for update
14:39:01,078 DEBUG EntityLoader:79 - Static select for entity com.cataphora.apps.production.test.item.ItemTest: select itemtest0_.item_test_id as item1_0_0_, itemtest0_.name as name0_0_ from item_test itemtest0_ where itemtest0_.item_test_id in (?, ?, ?, ?, ?) for update
14:39:01,078 DEBUG EntityLoader:79 - Static select for entity com.cataphora.apps.production.test.item.ItemTest: select itemtest0_.item_test_id as item1_0_0_, itemtest0_.name as name0_0_ from item_test itemtest0_ where itemtest0_.item_test_id in (?, ?, ?, ?) for update
14:39:01,078 DEBUG EntityLoader:79 - Static select for entity com.cataphora.apps.production.test.item.ItemTest: select itemtest0_.item_test_id as item1_0_0_, itemtest0_.name as name0_0_ from item_test itemtest0_ where itemtest0_.item_test_id in (?, ?, ?) for update
14:39:01,078 DEBUG EntityLoader:79 - Static select for entity com.cataphora.apps.production.test.item.ItemTest: select itemtest0_.item_test_id as item1_0_0_, itemtest0_.name as name0_0_ from item_test itemtest0_ where itemtest0_.item_test_id in (?, ?) for update
14:39:01,078 DEBUG EntityLoader:79 - Static select for entity com.cataphora.apps.production.test.item.ItemTest: select itemtest0_.item_test_id as item1_0_0_, itemtest0_.name as name0_0_ from item_test itemtest0_ where itemtest0_.item_test_id=? for update
14:39:01,078 DEBUG EntityLoader:79 - Static select for entity com.cataphora.apps.production.test.item.ItemTest: select itemtest0_.item_test_id as item1_0_0_, itemtest0_.name as name0_0_ from item_test itemtest0_ where itemtest0_.item_test_id in (?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?) for update
14:39:01,078 DEBUG EntityLoader:79 - Static select for entity com.cataphora.apps.production.test.item.ItemTest: select itemtest0_.item_test_id as item1_0_0_, itemtest0_.name as name0_0_ from item_test itemtest0_ where itemtest0_.item_test_id in (?, ?, ?, ?, ?, ?, ?, ?, ?, ?) for update
14:39:01,078 DEBUG EntityLoader:79 - Static select for entity com.cataphora.apps.production.test.item.ItemTest: select itemtest0_.item_test_id as item1_0_0_, itemtest0_.name as name0_0_ from item_test itemtest0_ where itemtest0_.item_test_id in (?, ?, ?, ?, ?, ?, ?, ?, ?) for update
14:39:01,078 DEBUG EntityLoader:79 - Static select for entity com.cataphora.apps.production.test.item.ItemTest: select itemtest0_.item_test_id as item1_0_0_, itemtest0_.name as name0_0_ from item_test itemtest0_ where itemtest0_.item_test_id in (?, ?, ?, ?, ?, ?, ?, ?) for update
14:39:01,078 DEBUG EntityLoader:79 - Static select for entity com.cataphora.apps.production.test.item.ItemTest: select itemtest0_.item_test_id as item1_0_0_, itemtest0_.name as name0_0_ from item_test itemtest0_ where itemtest0_.item_test_id in (?, ?, ?, ?, ?, ?, ?) for update
14:39:01,078 DEBUG EntityLoader:79 - Static select for entity com.cataphora.apps.production.test.item.ItemTest: select itemtest0_.item_test_id as item1_0_0_, itemtest0_.name as name0_0_ from item_test itemtest0_ where itemtest0_.item_test_id in (?, ?, ?, ?, ?, ?) for update
14:39:01,078 DEBUG EntityLoader:79 - Static select for entity com.cataphora.apps.production.test.item.ItemTest: select itemtest0_.item_test_id as item1_0_0_, itemtest0_.name as name0_0_ from item_test itemtest0_ where itemtest0_.item_test_id in (?, ?, ?, ?, ?) for update
14:39:01,078 DEBUG EntityLoader:79 - Static select for entity com.cataphora.apps.production.test.item.ItemTest: select itemtest0_.item_test_id as item1_0_0_, itemtest0_.name as name0_0_ from item_test itemtest0_ where itemtest0_.item_test_id in (?, ?, ?, ?) for update
14:39:01,078 DEBUG EntityLoader:79 - Static select for entity com.cataphora.apps.production.test.item.ItemTest: select itemtest0_.item_test_id as item1_0_0_, itemtest0_.name as name0_0_ from item_test itemtest0_ where itemtest0_.item_test_id in (?, ?, ?) for update
14:39:01,078 DEBUG EntityLoader:79 - Static select for entity com.cataphora.apps.production.test.item.ItemTest: select itemtest0_.item_test_id as item1_0_0_, itemtest0_.name as name0_0_ from item_test itemtest0_ where itemtest0_.item_test_id in (?, ?) for update
14:39:01,093 DEBUG EntityLoader:79 - Static select for entity com.cataphora.apps.production.test.item.ItemTest: select itemtest0_.item_test_id as item1_0_0_, itemtest0_.name as name0_0_ from item_test itemtest0_ where itemtest0_.item_test_id=? for update
14:39:01,109 DEBUG EntityLoader:34 - Static select for action ACTION_MERGE on entity com.cataphora.apps.production.test.item.ItemTest: select itemtest0_.item_test_id as item1_0_0_, itemtest0_.name as name0_0_ from item_test itemtest0_ where itemtest0_.item_test_id=?
14:39:01,109 DEBUG EntityLoader:34 - Static select for action ACTION_REFRESH on entity com.cataphora.apps.production.test.item.ItemTest: select itemtest0_.item_test_id as item1_0_0_, itemtest0_.name as name0_0_ from item_test itemtest0_ where itemtest0_.item_test_id=?
14:39:01,125 DEBUG BasicCollectionLoader:64 - Static select for collection com.cataphora.apps.production.test.item.ItemTest.properties: select properties0_.item_test_id as item1_0_, properties0_.property as property0_ from item_test_property properties0_ where properties0_.item_test_id in (?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?)
14:39:01,125 DEBUG BasicCollectionLoader:64 - Static select for collection com.cataphora.apps.production.test.item.ItemTest.properties: select properties0_.item_test_id as item1_0_, properties0_.property as property0_ from item_test_property properties0_ where properties0_.item_test_id in (?, ?, ?, ?, ?, ?, ?, ?, ?, ?)
14:39:01,125 DEBUG BasicCollectionLoader:64 - Static select for collection com.cataphora.apps.production.test.item.ItemTest.properties: select properties0_.item_test_id as item1_0_, properties0_.property as property0_ from item_test_property properties0_ where properties0_.item_test_id in (?, ?, ?, ?, ?, ?, ?, ?, ?)
14:39:01,125 DEBUG BasicCollectionLoader:64 - Static select for collection com.cataphora.apps.production.test.item.ItemTest.properties: select properties0_.item_test_id as item1_0_, properties0_.property as property0_ from item_test_property properties0_ where properties0_.item_test_id in (?, ?, ?, ?, ?, ?, ?, ?)
14:39:01,125 DEBUG BasicCollectionLoader:64 - Static select for collection com.cataphora.apps.production.test.item.ItemTest.properties: select properties0_.item_test_id as item1_0_, properties0_.property as property0_ from item_test_property properties0_ where properties0_.item_test_id in (?, ?, ?, ?, ?, ?, ?)
14:39:01,125 DEBUG BasicCollectionLoader:64 - Static select for collection com.cataphora.apps.production.test.item.ItemTest.properties: select properties0_.item_test_id as item1_0_, properties0_.property as property0_ from item_test_property properties0_ where properties0_.item_test_id in (?, ?, ?, ?, ?, ?)
14:39:01,125 DEBUG BasicCollectionLoader:64 - Static select for collection com.cataphora.apps.production.test.item.ItemTest.properties: select properties0_.item_test_id as item1_0_, properties0_.property as property0_ from item_test_property properties0_ where properties0_.item_test_id in (?, ?, ?, ?, ?)
14:39:01,125 DEBUG BasicCollectionLoader:64 - Static select for collection com.cataphora.apps.production.test.item.ItemTest.properties: select properties0_.item_test_id as item1_0_, properties0_.property as property0_ from item_test_property properties0_ where properties0_.item_test_id in (?, ?, ?, ?)
14:39:01,125 DEBUG BasicCollectionLoader:64 - Static select for collection com.cataphora.apps.production.test.item.ItemTest.properties: select properties0_.item_test_id as item1_0_, properties0_.property as property0_ from item_test_property properties0_ where properties0_.item_test_id in (?, ?, ?)
14:39:01,125 DEBUG BasicCollectionLoader:64 - Static select for collection com.cataphora.apps.production.test.item.ItemTest.properties: select properties0_.item_test_id as item1_0_, properties0_.property as property0_ from item_test_property properties0_ where properties0_.item_test_id in (?, ?)
14:39:01,125 DEBUG BasicCollectionLoader:64 - Static select for collection com.cataphora.apps.production.test.item.ItemTest.properties: select properties0_.item_test_id as item1_0_, properties0_.property as property0_ from item_test_property properties0_ where properties0_.item_test_id=?
14:39:01,140 DEBUG SessionFactoryObjectFactory:39 - initializing class SessionFactoryObjectFactory
14:39:01,140 DEBUG SessionFactoryObjectFactory:76 - registered: 8a8081c81df4b45d011df4b460050000 (unnamed)
14:39:01,140 INFO SessionFactoryObjectFactory:82 - Not binding factory to JNDI, no JNDI name configured
14:39:01,140 DEBUG SessionFactoryImpl:308 - instantiated session factory
14:39:01,171 DEBUG SessionFactoryImpl:392 - Checking 0 named HQL queries
14:39:01,171 DEBUG SessionFactoryImpl:412 - Checking 0 named SQL queries
14:39:01,234 DEBUG SessionImpl:220 - opened session at timestamp: 12281711412
14:39:01,359 DEBUG JDBCTransaction:54 - begin
14:39:01,359 DEBUG ConnectionManager:421 - opening JDBC connection
14:39:01,375 DEBUG JDBCTransaction:59 - current autocommit status: false
14:39:01,406 DEBUG AbstractSaveEventListener:297 - executing identity-insert immediately
14:39:01,421 DEBUG AbstractBatcher:366 - about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
14:39:01,421 DEBUG SQL:401 - insert into item_test (name) values (?)
Hibernate: insert into item_test (name) values (?)
14:39:01,484 DEBUG IdentifierGeneratorFactory:72 - Natively generated identity: 4
14:39:01,484 DEBUG AbstractBatcher:374 - about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
14:39:01,500 DEBUG AbstractSaveEventListener:297 - executing identity-insert immediately
14:39:01,500 DEBUG AbstractBatcher:366 - about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
14:39:01,500 DEBUG SQL:401 - insert into item_test (name) values (?)
Hibernate: insert into item_test (name) values (?)
14:39:01,500 DEBUG IdentifierGeneratorFactory:72 - Natively generated identity: 5
14:39:01,500 DEBUG AbstractBatcher:374 - about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
14:39:01,500 DEBUG AbstractSaveEventListener:297 - executing identity-insert immediately
14:39:01,500 DEBUG AbstractBatcher:366 - about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
14:39:01,500 DEBUG SQL:401 - insert into item_test (name) values (?)
Hibernate: insert into item_test (name) values (?)
14:39:01,515 DEBUG IdentifierGeneratorFactory:72 - Natively generated identity: 6
14:39:01,515 DEBUG AbstractBatcher:374 - about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
14:39:01,515 DEBUG JDBCTransaction:103 - commit
14:39:01,515 DEBUG AbstractFlushingEventListener:111 - processing flush-time cascades
14:39:01,515 DEBUG AbstractFlushingEventListener:154 - dirty checking collections
14:39:01,531 DEBUG Collections:176 - Collection found: [com.cataphora.apps.production.test.item.ItemTest.properties#4], was: [<unreferenced>] (initialized)
14:39:01,531 DEBUG Collections:176 - Collection found: [com.cataphora.apps.production.test.item.ItemTest.properties#5], was: [<unreferenced>] (initialized)
14:39:01,531 DEBUG Collections:176 - Collection found: [com.cataphora.apps.production.test.item.ItemTest.properties#6], was: [<unreferenced>] (initialized)
14:39:01,531 DEBUG AbstractFlushingEventListener:85 - Flushed: 0 insertions, 0 updates, 0 deletions to 3 objects
14:39:01,531 DEBUG AbstractFlushingEventListener:91 - Flushed: 3 (re)creations, 0 updates, 0 removals to 3 collections
14:39:01,531 DEBUG Printer:83 - listing entities:
14:39:01,546 DEBUG Printer:90 - com.cataphora.apps.production.test.item.ItemTest{properties=[prop9, prop8, prop7], name=C, id=6}
14:39:01,546 DEBUG Printer:90 - com.cataphora.apps.production.test.item.ItemTest{properties=[prop3, prop1, prop2], name=A, id=4}
14:39:01,546 DEBUG Printer:90 - com.cataphora.apps.production.test.item.ItemTest{properties=[prop4, prop6, prop5], name=B, id=5}
14:39:01,546 DEBUG AbstractCollectionPersister:1090 - Inserting collection: [com.cataphora.apps.production.test.item.ItemTest.properties#4]
14:39:01,562 DEBUG AbstractBatcher:366 - about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
14:39:01,562 DEBUG SQL:401 - insert into item_test_property (item_test_id, property) values (?, ?)
Hibernate: insert into item_test_property (item_test_id, property) values (?, ?)
14:39:01,562 DEBUG AbstractBatcher:226 - reusing prepared statement
14:39:01,562 DEBUG SQL:401 - insert into item_test_property (item_test_id, property) values (?, ?)
Hibernate: insert into item_test_property (item_test_id, property) values (?, ?)
14:39:01,562 DEBUG AbstractBatcher:226 - reusing prepared statement
14:39:01,562 DEBUG SQL:401 - insert into item_test_property (item_test_id, property) values (?, ?)
Hibernate: insert into item_test_property (item_test_id, property) values (?, ?)
14:39:01,562 DEBUG AbstractCollectionPersister:1172 - done inserting collection: 3 rows inserted
14:39:01,562 DEBUG AbstractCollectionPersister:1090 - Inserting collection: [com.cataphora.apps.production.test.item.ItemTest.properties#5]
14:39:01,562 DEBUG AbstractBatcher:226 - reusing prepared statement
14:39:01,562 DEBUG SQL:401 - insert into item_test_property (item_test_id, property) values (?, ?)
Hibernate: insert into item_test_property (item_test_id, property) values (?, ?)
14:39:01,578 DEBUG AbstractBatcher:226 - reusing prepared statement
14:39:01,578 DEBUG SQL:401 - insert into item_test_property (item_test_id, property) values (?, ?)
Hibernate: insert into item_test_property (item_test_id, property) values (?, ?)
14:39:01,578 DEBUG AbstractBatcher:226 - reusing prepared statement
14:39:01,578 DEBUG SQL:401 - insert into item_test_property (item_test_id, property) values (?, ?)
Hibernate: insert into item_test_property (item_test_id, property) values (?, ?)
14:39:01,578 DEBUG AbstractCollectionPersister:1172 - done inserting collection: 3 rows inserted
14:39:01,578 DEBUG AbstractCollectionPersister:1090 - Inserting collection: [com.cataphora.apps.production.test.item.ItemTest.properties#6]
14:39:01,578 DEBUG AbstractBatcher:226 - reusing prepared statement
14:39:01,578 DEBUG SQL:401 - insert into item_test_property (item_test_id, property) values (?, ?)
Hibernate: insert into item_test_property (item_test_id, property) values (?, ?)
14:39:01,578 DEBUG AbstractBatcher:226 - reusing prepared statement
14:39:01,578 DEBUG SQL:401 - insert into item_test_property (item_test_id, property) values (?, ?)
Hibernate: insert into item_test_property (item_test_id, property) values (?, ?)
14:39:01,578 DEBUG AbstractBatcher:226 - reusing prepared statement
14:39:01,578 DEBUG SQL:401 - insert into item_test_property (item_test_id, property) values (?, ?)
Hibernate: insert into item_test_property (item_test_id, property) values (?, ?)
14:39:01,578 DEBUG AbstractCollectionPersister:1172 - done inserting collection: 3 rows inserted
14:39:01,578 DEBUG AbstractBatcher:44 - Executing batch size: 9
14:39:01,578 DEBUG AbstractBatcher:374 - about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
14:39:01,625 DEBUG JDBCTransaction:116 - committed JDBC Connection
14:39:01,625 DEBUG ConnectionManager:404 - aggressively releasing JDBC connection
14:39:01,625 DEBUG ConnectionManager:441 - releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
14:39:01,625 DEBUG SessionImpl:220 - opened session at timestamp: 12281711416
14:39:01,625 DEBUG JDBCTransaction:54 - begin
14:39:01,625 DEBUG ConnectionManager:421 - opening JDBC connection
14:39:01,625 DEBUG JDBCTransaction:59 - current autocommit status: false
14:39:01,750 DEBUG QueryTranslatorImpl:246 - parse() - HQL: select it from com.cataphora.apps.production.test.item.ItemTest it left join fetch it.properties
14:39:01,781 DEBUG PARSER:42 - Keyword 'properties' is being interpreted as an identifier due to: expecting IDENT, found 'properties'
14:39:01,890 DEBUG AST:266 - --- HQL AST ---
\-[QUERY] 'query'
\-[SELECT_FROM] 'SELECT_FROM'
+-[FROM] 'from'
| +-[RANGE] 'RANGE'
| | +-[DOT] '.'
| | | +-[DOT] '.'
| | | | +-[DOT] '.'
| | | | | +-[DOT] '.'
| | | | | | +-[DOT] '.'
| | | | | | | +-[DOT] '.'
| | | | | | | | +-[IDENT] 'com'
| | | | | | | | \-[IDENT] 'cataphora'
| | | | | | | \-[IDENT] 'apps'
| | | | | | \-[IDENT] 'production'
| | | | | \-[IDENT] 'test'
| | | | \-[IDENT] 'item'
| | | \-[IDENT] 'ItemTest'
| | \-[ALIAS] 'it'
| \-[JOIN] 'join'
| +-[LEFT] 'left'
| +-[FETCH] 'fetch'
| \-[DOT] '.'
| +-[IDENT] 'it'
| \-[WEIRD_IDENT] 'properties'
\-[SELECT] 'select'
\-[IDENT] 'it'
14:39:01,890 DEBUG ErrorCounter:68 - throwQueryException() : no errors
14:39:01,984 DEBUG HqlSqlBaseWalker:111 - select << begin [level=1, statement=select]
14:39:02,031 DEBUG FromElement:108 - FromClause{level=1} : com.cataphora.apps.production.test.item.ItemTest (it) -> itemtest0_
14:39:02,031 DEBUG FromReferenceNode:51 - Resolved : it -> itemtest0_.item_test_id
14:39:02,031 DEBUG DotNode:569 - getDataType() : properties -> org.hibernate.type.SetType(com.cataphora.apps.production.test.item.ItemTest.properties)
14:39:02,046 DEBUG FromElement:108 - FromClause{level=1} : null (no alias) -> properties1_
14:39:02,046 DEBUG FromClause:324 - addCollectionJoinFromElementByPath() : it.properties -> item_test_property
14:39:02,046 DEBUG DotNode:284 - dereferenceCollection() : Created new FROM element for it.properties : item_test_property properties1_
14:39:02,046 DEBUG FromReferenceNode:51 - Resolved : it.properties -> .
14:39:02,046 DEBUG HqlSqlWalker:320 - createFromJoinElement() : -- join tree --
\-[JOIN_FRAGMENT] FromElement: 'item_test_property properties1_' FromElement{explicit,collection join,fetch join,fetch non-lazy properties,classAlias=null,role=com.cataphora.apps.production.test.item.ItemTest.properties,tableName={none},tableAlias=properties1_,origin=null,colums={,className=null}}
14:39:02,062 DEBUG FromReferenceNode:51 - Resolved : it -> itemtest0_.item_test_id
14:39:02,062 DEBUG HqlSqlBaseWalker:117 - select : finishing up [level=1, statement=select]
14:39:02,062 DEBUG HqlSqlWalker:509 - processQuery() : ( SELECT ( {select clause} itemtest0_.item_test_id ) ( FromClause{level=1} ( item_test_property properties1_ ) ) )
14:39:02,078 DEBUG JoinProcessor:148 - Using FROM fragment [item_test itemtest0_]
14:39:02,078 DEBUG JoinProcessor:148 - Using FROM fragment [left outer join item_test_property properties1_ on itemtest0_.item_test_id=properties1_.item_test_id]
14:39:02,078 DEBUG HqlSqlBaseWalker:123 - select >> end [level=1, statement=select]
14:39:02,093 DEBUG AST:232 - --- SQL AST ---
\-[SELECT] QueryNode: 'SELECT' querySpaces (item_test_property,item_test)
+-[SELECT_CLAUSE] SelectClause: '{select clause}'
| +-[ALIAS_REF] IdentNode: 'itemtest0_.item_test_id as item1_0_' {alias=it, className=com.cataphora.apps.production.test.item.ItemTest, tableAlias=itemtest0_}
| +-[SQL_TOKEN] SqlFragment: 'itemtest0_.name as name0_'
| \-[SQL_TOKEN] SqlFragment: 'properties1_.item_test_id as item1_0__, properties1_.property as property0__'
\-[FROM] FromClause: 'from' FromClause{level=1, fromElementCounter=1, fromElements=2, fromElementByClassAlias=[it], fromElementByTableAlias=[itemtest0_, properties1_], fromElementsByPath=[], collectionJoinFromElementsByPath=[it.properties], impliedElements=[]}
\-[FROM_FRAGMENT] FromElement: 'item_test itemtest0_' FromElement{explicit,collection join,not a fetch join,fetch non-lazy properties,classAlias=it,role=null,tableName=item_test,tableAlias=itemtest0_,origin=null,colums={,className=com.cataphora.apps.production.test.item.ItemTest}}
\-[JOIN_FRAGMENT] FromElement: 'left outer join item_test_property properties1_ on itemtest0_.item_test_id=properties1_.item_test_id' FromElement{explicit,collection join,fetch join,fetch non-lazy properties,classAlias=null,role=com.cataphora.apps.production.test.item.ItemTest.properties,tableName={none},tableAlias=properties1_,origin=item_test itemtest0_,colums={,className=null}}
14:39:02,093 DEBUG ErrorCounter:68 - throwQueryException() : no errors
14:39:02,125 DEBUG QueryTranslatorImpl:216 - HQL: select it from com.cataphora.apps.production.test.item.ItemTest it left join fetch it.properties
14:39:02,125 DEBUG QueryTranslatorImpl:217 - SQL: select itemtest0_.item_test_id as item1_0_, itemtest0_.name as name0_, properties1_.item_test_id as item1_0__, properties1_.property as property0__ from item_test itemtest0_ left outer join item_test_property properties1_ on itemtest0_.item_test_id=properties1_.item_test_id
14:39:02,125 DEBUG ErrorCounter:68 - throwQueryException() : no errors
14:39:02,156 DEBUG AbstractBatcher:366 - about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
14:39:02,156 DEBUG SQL:401 - select itemtest0_.item_test_id as item1_0_, itemtest0_.name as name0_, properties1_.item_test_id as item1_0__, properties1_.property as property0__ from item_test itemtest0_ left outer join item_test_property properties1_ on itemtest0_.item_test_id=properties1_.item_test_id
Hibernate: select itemtest0_.item_test_id as item1_0_, itemtest0_.name as name0_, properties1_.item_test_id as item1_0__, properties1_.property as property0__ from item_test itemtest0_ left outer join item_test_property properties1_ on itemtest0_.item_test_id=properties1_.item_test_id
14:39:02,171 DEBUG AbstractBatcher:382 - about to open ResultSet (open ResultSets: 0, globally: 0)
14:39:02,171 DEBUG Loader:1173 - result row: EntityKey[com.cataphora.apps.production.test.item.ItemTest#1]
14:39:02,187 DEBUG Loader:985 - found row of collection: [com.cataphora.apps.production.test.item.ItemTest.properties#1]
14:39:02,203 DEBUG Loader:1173 - result row: EntityKey[com.cataphora.apps.production.test.item.ItemTest#1]
14:39:02,203 DEBUG Loader:985 - found row of collection: [com.cataphora.apps.production.test.item.ItemTest.properties#1]
14:39:02,203 DEBUG Loader:1173 - result row: EntityKey[com.cataphora.apps.production.test.item.ItemTest#1]
14:39:02,203 DEBUG Loader:985 - found row of collection: [com.cataphora.apps.production.test.item.ItemTest.properties#1]
14:39:02,203 DEBUG Loader:1173 - result row: EntityKey[com.cataphora.apps.production.test.item.ItemTest#2]
14:39:02,203 DEBUG Loader:985 - found row of collection: [com.cataphora.apps.production.test.item.ItemTest.properties#2]
14:39:02,203 DEBUG TwoPhaseLoad:111 - resolving associations for [com.cataphora.apps.production.test.item.ItemTest#1]
14:39:02,203 DEBUG TwoPhaseLoad:209 - done materializing entity [com.cataphora.apps.production.test.item.ItemTest#1]
14:39:02,203 DEBUG TwoPhaseLoad:111 - resolving associations for [com.cataphora.apps.production.test.item.ItemTest#2]
14:39:02,203 DEBUG TwoPhaseLoad:209 - done materializing entity [com.cataphora.apps.production.test.item.ItemTest#2]
14:39:02,203 DEBUG CollectionLoadContext:217 - 2 collections were found in result set for role: com.cataphora.apps.production.test.item.ItemTest.properties
14:39:02,203 DEBUG CollectionLoadContext:263 - collection fully initialized: [com.cataphora.apps.production.test.item.ItemTest.properties#2]
14:39:02,203 DEBUG CollectionLoadContext:263 - collection fully initialized: [com.cataphora.apps.production.test.item.ItemTest.properties#1]
14:39:02,203 DEBUG CollectionLoadContext:226 - 2 collections initialized for role: com.cataphora.apps.production.test.item.ItemTest.properties
14:39:02,203 DEBUG StatefulPersistenceContext:837 - initializing non-lazy collections
A
prop3
prop1
prop2
==============
14:39:02,203 DEBUG Loader:1173 - result row: EntityKey[com.cataphora.apps.production.test.item.ItemTest#2]
14:39:02,218 DEBUG Loader:985 - found row of collection: [com.cataphora.apps.production.test.item.ItemTest.properties#2]
14:39:02,218 DEBUG Loader:1173 - result row: EntityKey[com.cataphora.apps.production.test.item.ItemTest#2]
14:39:02,218 DEBUG Loader:985 - found row of collection: [com.cataphora.apps.production.test.item.ItemTest.properties#2]
14:39:02,218 DEBUG Loader:1173 - result row: EntityKey[com.cataphora.apps.production.test.item.ItemTest#2]
14:39:02,218 DEBUG Loader:985 - found row of collection: [com.cataphora.apps.production.test.item.ItemTest.properties#2]
14:39:02,218 DEBUG Loader:1173 - result row: EntityKey[com.cataphora.apps.production.test.item.ItemTest#3]
14:39:02,218 DEBUG Loader:985 - found row of collection: [com.cataphora.apps.production.test.item.ItemTest.properties#3]
14:39:02,218 DEBUG TwoPhaseLoad:111 - resolving associations for [com.cataphora.apps.production.test.item.ItemTest#3]
14:39:02,218 DEBUG TwoPhaseLoad:209 - done materializing entity [com.cataphora.apps.production.test.item.ItemTest#3]
14:39:02,218 DEBUG CollectionLoadContext:217 - 1 collections were found in result set for role: com.cataphora.apps.production.test.item.ItemTest.properties
14:39:02,218 DEBUG CollectionLoadContext:263 - collection fully initialized: [com.cataphora.apps.production.test.item.ItemTest.properties#3]
14:39:02,218 DEBUG CollectionLoadContext:226 - 1 collections initialized for role: com.cataphora.apps.production.test.item.ItemTest.properties
14:39:02,218 DEBUG StatefulPersistenceContext:837 - initializing non-lazy collections
B
prop4
==============
14:39:02,218 DEBUG Loader:1173 - result row: EntityKey[com.cataphora.apps.production.test.item.ItemTest#3]
14:39:02,218 DEBUG Loader:985 - found row of collection: [com.cataphora.apps.production.test.item.ItemTest.properties#3]
14:39:02,218 DEBUG Loader:1173 - result row: EntityKey[com.cataphora.apps.production.test.item.ItemTest#3]
14:39:02,218 DEBUG Loader:985 - found row of collection: [com.cataphora.apps.production.test.item.ItemTest.properties#3]
14:39:02,218 DEBUG Loader:1173 - result row: EntityKey[com.cataphora.apps.production.test.item.ItemTest#3]
14:39:02,218 DEBUG Loader:985 - found row of collection: [com.cataphora.apps.production.test.item.ItemTest.properties#3]
14:39:02,218 DEBUG Loader:1173 - result row: EntityKey[com.cataphora.apps.production.test.item.ItemTest#4]
14:39:02,218 DEBUG Loader:985 - found row of collection: [com.cataphora.apps.production.test.item.ItemTest.properties#4]
14:39:02,218 DEBUG TwoPhaseLoad:111 - resolving associations for [com.cataphora.apps.production.test.item.ItemTest#4]
14:39:02,218 DEBUG TwoPhaseLoad:209 - done materializing entity [com.cataphora.apps.production.test.item.ItemTest#4]
14:39:02,218 DEBUG CollectionLoadContext:217 - 1 collections were found in result set for role: com.cataphora.apps.production.test.item.ItemTest.properties
14:39:02,218 DEBUG CollectionLoadContext:263 - collection fully initialized: [com.cataphora.apps.production.test.item.ItemTest.properties#4]
14:39:02,234 DEBUG CollectionLoadContext:226 - 1 collections initialized for role: com.cataphora.apps.production.test.item.ItemTest.properties
14:39:02,234 DEBUG StatefulPersistenceContext:837 - initializing non-lazy collections
C
prop9
==============
14:39:02,234 DEBUG Loader:1173 - result row: EntityKey[com.cataphora.apps.production.test.item.ItemTest#4]
14:39:02,234 DEBUG Loader:985 - found row of collection: [com.cataphora.apps.production.test.item.ItemTest.properties#4]
14:39:02,234 DEBUG Loader:1173 - result row: EntityKey[com.cataphora.apps.production.test.item.ItemTest#4]
14:39:02,234 DEBUG Loader:985 - found row of collection: [com.cataphora.apps.production.test.item.ItemTest.properties#4]
14:39:02,234 DEBUG Loader:1173 - result row: EntityKey[com.cataphora.apps.production.test.item.ItemTest#4]
14:39:02,234 DEBUG Loader:985 - found row of collection: [com.cataphora.apps.production.test.item.ItemTest.properties#4]
14:39:02,234 DEBUG Loader:1173 - result row: EntityKey[com.cataphora.apps.production.test.item.ItemTest#5]
14:39:02,234 DEBUG Loader:985 - found row of collection: [com.cataphora.apps.production.test.item.ItemTest.properties#5]
14:39:02,234 DEBUG TwoPhaseLoad:111 - resolving associations for [com.cataphora.apps.production.test.item.ItemTest#5]
14:39:02,234 DEBUG TwoPhas
Login
FAQ
Search
