Hi,
I am having some trouble writing a history listener.
I have mapped my objects using entity names, eg: the CatEntity pojo is mapped twice, as Cat and CatHistory, both identical but writing to different tables.
I have a listener that fires before an object is updated. It creates a new session, reads the current version of the object, writes it to a history table (using entity name), and return. The main process then writes the changes to the main table.
It all works fine except when I have a collection on the object. When I store the history object, Hibernate issues a delete against the collection in the
parent object, ala:
Quote:
>>> BEGIN FLUSH
+++ BEGIN HISTORY +++
Hibernate: select cat0_.id as id0_0_, cat0_.version as version0_0_, cat0_.name as name0_0_, cat0_.type as type0_0_ from Cat cat0_ where cat0_.id=?
Hibernate: select mice0_.cat as cat0_, mice0_.rabid as rabid0_, mice0_.description as descript3_0_, mice0_.species as species0_ from Mouse mice0_ where mice0_.cat=? order by mice0_.description
Hibernate: insert into CatHist (name, type, id, version) values (?, ?, ?, ?)
Hibernate: delete from Mouse where cat=?
Hibernate: insert into MouseHist (cat, version, rabid, description, species) values (?, ?, ?, ?, ?)
+++ END HISTORY +++
Hibernate: update Cat set version=?, name=?, type=? where id=? and version=?
Hibernate: delete from Mouse where cat=? and rabid=? and description=? and species=?
Hibernate: insert into Mouse (cat, rabid, description, species) values (?, ?, ?, ?)
Hibernate: insert into Mouse (cat, rabid, description, species) values (?, ?, ?, ?)
Hibernate: insert into Mouse (cat, rabid, description, species) values (?, ?, ?, ?)
Hibernate: insert into Mouse (cat, rabid, description, species) values (?, ?, ?, ?)
<<< END FLUSH
I don't know why it is trying to clear the collection on the parent object when I am not touching it in the history listener - unless simply reading the collection makes it dirty? I have tried it with sets and bags with no change.
As you can see, it re-creates the collection once the history listener is finished. However, this only happens in unit tests. In my Spring MVC webapp, if I load an object and save it again, the collection is deleted but not recreated.
This is all a bit complex I know. If you need any more information please let me know!
Hibernate version: 3.3.0CR1
Mapping documents:Code:
<?xml version="1.0"?>
<!DOCTYPE hibernate-mapping PUBLIC
"-//Hibernate/Hibernate Mapping DTD//EN"
"http://hibernate.sourceforge.net/hibernate-mapping-3.0.dtd">
<hibernate-mapping package="test.hib3local">
<class name="CatEntity" table="Cat" entity-name="Cat">
<id name="id" type="long">
<generator class="hilo" />
</id>
<version name="version" type="long" />
<property name="name"/>
<property name="type"/>
<set name="mice" table="Mouse" order-by="description">
<key column="cat" not-null="true"/>
<composite-element class="MouseImpl">
<property name="rabid" />
<property name="description" />
<nested-composite-element name="species" class="Species">
<property name="species" column="species"/>
</nested-composite-element>
</composite-element>
</set>
</class>
<class name="CatEntity" table="CatHist" entity-name="CatHistory">
<composite-id class="au.gov.sa.dcs.base.entity.HistoryPK" mapped="true">
<key-property name="id" type="long" />
<key-property name="version" type="long" />
</composite-id>
<property name="name"/>
<property name="type"/>
<set name="mice" table="MouseHist" order-by="description">
<key>
<column name="cat" not-null="true"/>
<column name="version" not-null="true"/>
</key>
<composite-element class="MouseImpl">
<property name="rabid" />
<property name="description" />
<nested-composite-element name="species" class="Species">
<property name="species" column="species"/>
</nested-composite-element>
</composite-element>
</set>
</class>
</hibernate-mapping>
Code between sessionFactory.openSession() and session.close():Code:
package test.hib3.junit;
import java.util.Iterator;
import java.util.List;
import junit.framework.TestCase;
import org.hibernate.Session;
import org.hibernate.SessionFactory;
import org.hibernate.Transaction;
import org.hibernate.cfg.Configuration;
import org.hibernate.event.PostDeleteEventListener;
import org.hibernate.event.PostInsertEventListener;
import org.hibernate.event.PostUpdateEventListener;
import org.hibernate.event.PreUpdateEventListener;
import test.hib3.Cat;
import test.hib3local.CatEntity;
import test.hib3local.Species;
import test.hib3local.MouseImpl;
import au.gov.sa.dcs.base.entity.Audit;
import au.gov.sa.dcs.base.entity.hibernate.AuditEventListener;
import au.gov.sa.dcs.base.entity.hibernate.HistoryEventListener;
public class CatTest extends TestCase {
public void testCat() {
Configuration config = getConfig();
HistoryEventListener historyEventListener = new HistoryEventListener();
config.getEventListeners().setPreUpdateEventListeners(new PreUpdateEventListener[] {historyEventListener});
SessionFactory sessionFactory = config.buildSessionFactory();
Session session = sessionFactory.openSession();
Transaction transaction = session.beginTransaction();
Cat cat = new CatEntity();
cat.setName("Miffy");
cat.setType("Tabby");
cat.getMice().add(new MouseImpl("A"));
session.save(cat.getEntityName(), cat);
System.out.println("\n***** PASS 1 ******");
this.flush(session);
Cat cat2 = (Cat) session.load("Cat", new Long(1));
cat2.setName("Foo");
cat2.setType("Persian");
cat2.getMice().add(new MouseImpl("B", true));
cat2.getMice().add(new MouseImpl("C", false, new Species("Brown")));
cat2.getMice().add(new MouseImpl("D", false, new Species("Red")));
session.update(cat2);
System.out.println("\n***** PASS 2 ******");
this.flush(session);
Cat cat3 = (Cat) session.load("Cat", new Long(1));
cat2.getMice().clear();
cat2.getMice().add(new MouseImpl("E"));
cat2.getMice().add(new MouseImpl("F", true, new Species("Fuschia")));
cat3.setName("Tinky");
cat3.setType("fluffy");
System.out.println("\n***** PASS 3 ******");
session.update(cat3);
this.flush(session);
transaction.commit();
assertListObject(session, "Cat", 1);
assertListObject(session, "CatHistory", 2);
}
private void assertListObject(Session session, String entity, int count) {
assertEquals(entity, count, listObject(session, entity).size());
}
private List listObject(Session session, String entity) {
System.out.println("*** "+ entity +" ***");
List list = session.createQuery("from "+ entity).list();
for (Iterator itr = list.iterator(); itr.hasNext();) {
System.out.println(itr.next());
}
return list;
}
private void flush(Session session) {
System.out.println(">>> BEGIN FLUSH");
session.flush();
System.out.println("<<< END FLUSH");
}
private Configuration getConfig() {
return new Configuration().
setProperty("hibernate.dialect", "org.hibernate.dialect.HSQLDialect").
setProperty("hibernate.connection.driver_class", "org.hsqldb.jdbcDriver").
setProperty("hibernate.connection.url", "jdbc:hsqldb:mem:baseball").
setProperty("hibernate.connection.username", "sa").
setProperty("hibernate.connection.password", "").
setProperty("hibernate.connection.pool_size", "1").
setProperty("hibernate.connection.autocommit", "true").
setProperty("hibernate.cache.provider_class", "org.hibernate.cache.HashtableCacheProvider").
setProperty("hibernate.hbm2ddl.auto", "create-drop").
setProperty("hibernate.show_sql", "true").
addClass(CatEntity.class);
}
}
And the history listener:
Code:
public class HistoryEventListener implements PreUpdateEventListener {
private static final Log log = LogFactory.getLog(HistoryEventListener.class);
private static final long serialVersionUID = 1L;
/**
*
* @param event
* @return
*/
public boolean onPreUpdate(PreUpdateEvent event) {
return saveHistoryEntity(event.getEntity(), event.getId(), event.getSource());
}
/**
*
* @param event
* @return
*/
private boolean saveHistoryEntity(Object entity, Serializable id, SessionImplementor parentSession) {
//check for historizable entities
if (entity instanceof Historizable) {
log.debug("*** saveHistoryEntity("+entity.getClass().getSimpleName() +", "+ id +")");
System.out.println("+++ BEGIN HISTORY +++");
//get parent connection
Connection connection = parentSession.connection();
try {
//get entity name
AuditedEntity historizableEntity = (AuditedEntity) entity;
String entityName = historizableEntity.getEntityName();
String historyEntityName = historizableEntity.getHistoryEntityName();
//grab a temporary session
Session session = parentSession.getFactory().openSession(connection);
session.setCacheMode(CacheMode.IGNORE);
session.setFlushMode(FlushMode.MANUAL);
//load the old (that is, current) version of this entity
AuditedEntity previous = (AuditedEntity) session.load(entityName, id);
//populate the history PK
previous.populateHistoryPK();
//evict from session cache to make sure it inserts
session.evict(previous);
//insert using the history entity name
session.save(historyEntityName, previous);
//flush and close
session.flush();
session.close();
} finally {
try {
//close connection from parent session
//TODO: confirm this is required - session.connection() apparently does create a new connection
connection.close();
} catch (SQLException e) {
throw new IllegalStateException("Exception closing connection: "+ e.getMessage(), e);
}
}
System.out.println("+++ END HISTORY +++");
}
return false;
}
}
Name and version of the database you are using:HSQLDB for unit test, MSSQL 8 for web
The generated SQL (show_sql=true):Quote:
***** PASS 1 ******
>>> BEGIN FLUSH
Hibernate: insert into Cat (version, name, type, id) values (?, ?, ?, ?)
Hibernate: insert into Mouse (cat, rabid, description, species) values (?, ?, ?, ?)
<<< END FLUSH
***** PASS 2 ******
>>> BEGIN FLUSH
+++ BEGIN HISTORY +++
Hibernate: select cat0_.id as id0_0_, cat0_.version as version0_0_, cat0_.name as name0_0_, cat0_.type as type0_0_ from Cat cat0_ where cat0_.id=?
Hibernate: select mice0_.cat as cat0_, mice0_.rabid as rabid0_, mice0_.description as descript3_0_, mice0_.species as species0_ from Mouse mice0_ where mice0_.cat=? order by mice0_.description
Hibernate: insert into CatHist (name, type, id, version) values (?, ?, ?, ?)
Hibernate: delete from Mouse where cat=?
Hibernate: insert into MouseHist (cat, version, rabid, description, species) values (?, ?, ?, ?, ?)
+++ END HISTORY +++
Hibernate: update Cat set version=?, name=?, type=? where id=? and version=?
Hibernate: delete from Mouse where cat=? and rabid=? and description=? and species=?
Hibernate: insert into Mouse (cat, rabid, description, species) values (?, ?, ?, ?)
Hibernate: insert into Mouse (cat, rabid, description, species) values (?, ?, ?, ?)
Hibernate: insert into Mouse (cat, rabid, description, species) values (?, ?, ?, ?)
Hibernate: insert into Mouse (cat, rabid, description, species) values (?, ?, ?, ?)
<<< END FLUSH
Debug level Hibernate log excerpt:
[quote]
2008-05-21 14:32:41,123 INFO Environment :: main :: Hibernate 3.2.6
2008-05-21 14:32:41,123 INFO Environment :: main :: hibernate.properties not found
2008-05-21 14:32:41,138 INFO Environment :: main :: Bytecode provider name : cglib
2008-05-21 14:32:41,138 INFO Environment :: main :: using JDK 1.4 java.sql.Timestamp handling
2008-05-21 14:32:41,263 INFO Configuration :: main :: Reading mappings from resource: test/hib3local/CatEntity.hbm.xml
2008-05-21 14:32:41,263 INFO Configuration :: main :: Reading mappings from resource: test/hib3local/CatEntity.hbm.xml
2008-05-21 14:32:41,529 DEBUG DTDEntityResolver :: main :: trying to resolve system-id [http://hibernate.sourceforge.net/hibernate-mapping-3.0.dtd]
2008-05-21 14:32:41,529 DEBUG DTDEntityResolver :: main :: recognized hibernate namespace; attempting to resolve on classpath under org/hibernate/
2008-05-21 14:32:41,654 DEBUG DTDEntityResolver :: main :: located [http://hibernate.sourceforge.net/hibernate-mapping-3.0.dtd] in classpath
2008-05-21 14:32:41,951 INFO HbmBinder :: main :: Mapping class: Cat -> Cat
2008-05-21 14:32:41,966 DEBUG HbmBinder :: main :: Mapped property: id -> id
2008-05-21 14:32:41,966 DEBUG HbmBinder :: main :: Mapped property: version -> version
2008-05-21 14:32:42,013 DEBUG HbmBinder :: main :: Mapped property: name -> name
2008-05-21 14:32:42,013 DEBUG HbmBinder :: main :: Mapped property: type -> type
2008-05-21 14:32:42,029 INFO HbmBinder :: main :: Mapping collection: Cat.mice -> Mouse
2008-05-21 14:32:42,029 DEBUG HbmBinder :: main :: Mapped property: mice
2008-05-21 14:32:42,029 INFO HbmBinder :: main :: Mapping class: CatHistory -> CatHist
2008-05-21 14:32:42,029 DEBUG HbmBinder :: main :: Mapped property: id -> id
2008-05-21 14:32:42,029 DEBUG HbmBinder :: main :: Mapped property: version -> version
2008-05-21 14:32:42,029 DEBUG HbmBinder :: main :: Mapped property: id -> id
2008-05-21 14:32:42,029 DEBUG HbmBinder :: main :: Mapped property: version -> version
2008-05-21 14:32:42,029 DEBUG HbmBinder :: main :: Mapped property: name -> name
2008-05-21 14:32:42,029 DEBUG HbmBinder :: main :: Mapped property: type -> type
2008-05-21 14:32:42,029 INFO HbmBinder :: main :: Mapping collection: CatHistory.mice -> MouseHist
2008-05-21 14:32:42,029 DEBUG HbmBinder :: main :: Mapped property: mice
2008-05-21 14:32:42,044 DEBUG Configuration :: main :: Preparing to build session factory with filters : {}
2008-05-21 14:32:42,044 DEBUG Configuration :: main :: processing extends queue
2008-05-21 14:32:42,044 DEBUG Configuration :: main :: processing collection mappings
2008-05-21 14:32:42,044 DEBUG CollectionSecondPass :: main :: Second pass for collection: Cat.mice
2008-05-21 14:32:42,044 DEBUG HbmBinder :: main :: Mapped property: rabid -> rabid
2008-05-21 14:32:42,044 DEBUG HbmBinder :: main :: Mapped property: description -> description
2008-05-21 14:32:42,044 DEBUG HbmBinder :: main :: Mapped property: species -> species
2008-05-21 14:32:42,044 DEBUG HbmBinder :: main :: Mapped property: species -> species
2008-05-21 14:32:42,044 DEBUG CollectionSecondPass :: main :: Mapped collection key: cat, element: rabid, description, species
2008-05-21 14:32:42,044 DEBUG CollectionSecondPass :: main :: Second pass for collection: CatHistory.mice
2008-05-21 14:32:42,044 DEBUG HbmBinder :: main :: Mapped property: rabid -> rabid
2008-05-21 14:32:42,044 DEBUG HbmBinder :: main :: Mapped property: description -> description
2008-05-21 14:32:42,044 DEBUG HbmBinder :: main :: Mapped property: species -> species
2008-05-21 14:32:42,044 DEBUG HbmBinder :: main :: Mapped property: species -> species
2008-05-21 14:32:42,044 DEBUG CollectionSecondPass :: main :: Mapped collection key: cat, version, element: rabid, description, species
2008-05-21 14:32:42,044 DEBUG Configuration :: main :: processing native query and ResultSetMapping mappings
2008-05-21 14:32:42,044 DEBUG Configuration :: main :: processing association property references
2008-05-21 14:32:42,044 DEBUG Configuration :: main :: processing foreign key constraints
2008-05-21 14:32:42,044 DEBUG Configuration :: main :: resolving reference to class: Cat
2008-05-21 14:32:42,044 DEBUG Configuration :: main :: resolving reference to class: CatHistory
2008-05-21 14:32:42,248 INFO DriverManagerConnectionProvider :: main :: Using Hibernate built-in connection pool (not for production use!)
2008-05-21 14:32:42,248 INFO DriverManagerConnectionProvider :: main :: Hibernate connection pool size: 1
2008-05-21 14:32:42,248 INFO DriverManagerConnectionProvider :: main :: autocommit mode: true
2008-05-21 14:32:42,248 INFO DriverManagerConnectionProvider :: main :: using driver: org.hsqldb.jdbcDriver at URL: jdbc:hsqldb:mem:baseball
2008-05-21 14:32:42,248 INFO DriverManagerConnectionProvider :: main :: connection properties: {user=sa, password=, autocommit=true}
2008-05-21 14:32:42,248 DEBUG DriverManagerConnectionProvider :: main :: total checked-out connections: 0
2008-05-21 14:32:42,248 DEBUG DriverManagerConnectionProvider :: main :: opening new JDBC connection
2008-05-21 14:32:42,591 DEBUG DriverManagerConnectionProvider :: main :: created connection to: jdbc:hsqldb:mem:baseball, Isolation Level: 2
2008-05-21 14:32:42,638 INFO SettingsFactory :: main :: RDBMS: HSQL Database Engine, version: 1.8.0
2008-05-21 14:32:42,638 INFO SettingsFactory :: main :: JDBC driver: HSQL Database Engine Driver, version: 1.8.0
2008-05-21 14:32:42,638 DEBUG DriverManagerConnectionProvider :: main :: returning connection to pool, pool size: 1
2008-05-21 14:32:42,669 INFO Dialect :: main :: Using dialect: org.hibernate.dialect.HSQLDialect
2008-05-21 14:32:42,685 INFO TransactionFactoryFactory :: main :: Using default transaction strategy (direct JDBC transactions)
2008-05-21 14:32:42,685 INFO TransactionManagerLookupFactory :: main :: No TransactionManagerLookup configured (in JTA environment, use of read-write or transactional second-level cache is not recommended)
2008-05-21 14:32:42,685 INFO SettingsFactory :: main :: Automatic flush during beforeCompletion(): disabled
2008-05-21 14:32:42,685 INFO SettingsFactory :: main :: Automatic session close at end of transaction: disabled
2008-05-21 14:32:42,685 INFO SettingsFactory :: main :: JDBC batch size: 15
2008-05-21 14:32:42,685 INFO SettingsFactory :: main :: JDBC batch updates for versioned data: disabled
2008-05-21 14:32:42,685 INFO SettingsFactory :: main :: Scrollable result sets: enabled
2008-05-21 14:32:42,685 DEBUG SettingsFactory :: main :: Wrap result sets: disabled
2008-05-21 14:32:42,685 INFO SettingsFactory :: main :: JDBC3 getGeneratedKeys(): disabled
2008-05-21 14:32:42,685 INFO SettingsFactory :: main :: Connection release mode: auto
2008-05-21 14:32:42,685 INFO SettingsFactory :: main :: Default batch fetch size: 1
2008-05-21 14:32:42,685 INFO SettingsFactory :: main :: Generate SQL with comments: disabled
2008-05-21 14:32:42,685 INFO SettingsFactory :: main :: Order SQL updates by primary key: disabled
2008-05-21 14:32:42,685 INFO SettingsFactory :: main :: Order SQL inserts for batching: disabled
2008-05-21 14:32:42,685 INFO SettingsFactory :: main :: Query translator: org.hibernate.hql.ast.ASTQueryTranslatorFactory
2008-05-21 14:32:42,685 INFO ASTQueryTranslatorFactory :: main :: Using ASTQueryTranslatorFactory
2008-05-21 14:32:42,685 INFO SettingsFactory :: main :: Query language substitutions: {}
2008-05-21 14:32:42,685 INFO SettingsFactory :: main :: JPA-QL strict compliance: disabled
2008-05-21 14:32:42,685 INFO SettingsFactory :: main :: Second-level cache: enabled
2008-05-21 14:32:42,701 INFO SettingsFactory :: main :: Query cache: disabled
2008-05-21 14:32:42,701 INFO SettingsFactory :: main :: Cache provider: org.hibernate.cache.HashtableCacheProvider
2008-05-21 14:32:42,701 INFO SettingsFactory :: main :: Optimize cache for minimal puts: disabled
2008-05-21 14:32:42,701 INFO SettingsFactory :: main :: Structured second-level cache entries: disabled
2008-05-21 14:32:42,701 DEBUG SQLExceptionConverterFactory :: main :: Using dialect defined converter
2008-05-21 14:32:42,701 INFO SettingsFactory :: main :: Echoing all SQL to stdout
2008-05-21 14:32:42,701 INFO SettingsFactory :: main :: Statistics: disabled
2008-05-21 14:32:42,701 INFO SettingsFactory :: main :: Deleted entity synthetic identifier rollback: disabled
2008-05-21 14:32:42,701 INFO SettingsFactory :: main :: Default entity-mode: pojo
2008-05-21 14:32:42,701 INFO SettingsFactory :: main :: Named query checking : enabled
2008-05-21 14:32:42,794 INFO SessionFactoryImpl :: main :: building session factory
2008-05-21 14:32:42,794 DEBUG SessionFactoryImpl :: main :: Session factory constructed with filter configurations : {}
2008-05-21 14:32:42,794 DEBUG SessionFactoryImpl :: main :: instantiating session factory with properties: {java.runtime.name=Java(TM) 2 Runtime Environment, Standard Edition, hibernate.connection.password=, hibernate.cache.provider_class=org.hibernate.cache.HashtableCacheProvider, sun.boot.library.path=C:\bea10.2\jdk150_11\jre\bin, java.vm.version=1.5.0_11-b03, hibernate.connection.username=sa, 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=AU, sun.java.launcher=SUN_STANDARD, sun.os.patch.level=Service Pack 2, java.vm.specification.name=Java Virtual Machine Specification, user.dir=D:\Eclipse\newWorkspace\Hiberate3Test, java.runtime.version=1.5.0_11-b03, java.awt.graphicsenv=sun.awt.Win32GraphicsEnvironment, java.endorsed.dirs=C:\bea10.2\jdk150_11\jre\lib\endorsed, os.arch=x86, hibernate.connection.autocommit=true, java.io.tmpdir=C:\DOCUME~1\CONTTL\LOCALS~1\Temp\, line.separator=
, java.vm.specification.vendor=Sun Microsystems Inc., user.variant=, os.name=Windows XP, sun.jnu.encoding=Cp1252, java.library.path=C:\bea10.2\jdk150_11\bin;.;C:\WINDOWS\system32;C:\WINDOWS;C:\Program Files\Support Tools\;C:\WINDOWS\system32;C:\WINDOWS;C:\WINDOWS\System32\Wbem;C:\PROGRA~1\CA\Common\SCANEN~1;C:\PROGRA~1\CA\eTrust\INOCUL~1;C:\WINDOWS\system32\nls;C:\WINDOWS\system32\nls\ENGLISH;C:\Program Files\Microsoft SQL Server\80\Tools\BINN;c:\cvsnt;D:\apache-maven-2.0.8\bin, 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\CONTTL, user.timezone=Australia/Adelaide, java.awt.printerjob=sun.awt.windows.WPrinterJob, java.specification.version=1.5, file.encoding=Cp1252, hibernate.connection.driver_class=org.hsqldb.jdbcDriver, java.class.path=D:\Eclipse\newWorkspace\Hiberate3Test\bin;X:\javaResources\junit\junit\junit3.8.1\junit.jar;X:\javaResources\sourceforge\hibernate\hibernate-3.2\hibernate3.jar;X:\javaResources\sourceforge\hibernate\hibernate-3.2\lib\ant-1.6.5.jar;X:\javaResources\sourceforge\hibernate\hibernate-3.2\lib\ant-antlr-1.6.5.jar;X:\javaResources\sourceforge\hibernate\hibernate-3.2\lib\ant-junit-1.6.5.jar;X:\javaResources\sourceforge\hibernate\hibernate-3.2\lib\ant-launcher-1.6.5.jar;X:\javaResources\sourceforge\hibernate\hibernate-3.2\lib\antlr-2.7.6.jar;X:\javaResources\sourceforge\hibernate\hibernate-3.2\lib\ant-swing-1.6.5.jar;X:\javaResources\sourceforge\hibernate\hibernate-3.2\lib\asm.jar;X:\javaResources\sourceforge\hibernate\hibernate-3.2\lib\asm-attrs.jar;X:\javaResources\sourceforge\hibernate\hibernate-3.2\lib\c3p0-0.9.1.jar;X:\javaResources\sourceforge\hibernate\hibernate-3.2\lib\cglib-2.1.3.jar;X:\javaResources\sourceforge\hibernate\hibernate-3.2\lib\checkstyle-all.jar;X:\javaResources\sourceforge\hibernate\hibernate-3.2\lib\cleanimports.jar;X:\javaResources\sourceforge\hibernate\hibernate-3.2\lib\commons-collections-2.1.1.jar;X:\javaResources\sourceforge\hibernate\hibernate-3.2\lib\commons-logging-1.0.4.jar;X:\javaResources\sourceforge\hibernate\hibernate-3.2\lib\concurrent-1.3.2.jar;X:\javaResources\sourceforge\hibernate\hibernate-3.2\lib\dom4j-1.6.1.jar;X:\javaResources\sourceforge\hibernate\hibernate-3.2\lib\ehcache-1.2.3.jar;X:\javaResources\sourceforge\hibernate\hibernate-3.2\lib\jaas.jar;X:\javaResources\sourceforge\hibernate\hibernate-3.2\lib\jacc-1_0-fr.jar;X:\javaResources\sourceforge\hibernate\hibernate-3.2\lib\javassist.jar;X:\javaResources\sourceforge\hibernate\hibernate-3.2\lib\jaxen-1.1-beta-7.jar;X:\javaResources\sourceforge\hibernate\hibernate-3.2\lib\jboss-cache.jar;X:\javaResources\sourceforge\hibernate\hibernate-3.2\lib\jboss-common.jar;X:\javaResources\sourceforge\hibernate\hibernate-3.2\lib\jboss-jmx.jar;X:\javaResources\sourceforge\hibernate\hibernate-3.2\lib\jboss-system.jar;X:\javaResources\sourceforge\hibernate\hibernate-3.2\lib\jgroups-2.2.8.jar;X:\javaResources\sourceforge\hibernate\hibernate-3.2\lib\jta.jar;X:\javaResources\sourceforge\hibernate\hibernate-3.2\lib\junit-3.8.1.jar;X:\javaResources\sourceforge\hibernate\hibernate-3.2\lib\log4j-1.2.11.jar;X:\javaResources\sourceforge\hibernate\hibernate-3.2\lib\oscache-2.1.jar;X:\javaResources\sourceforge\hibernate\hibernate-3.2\lib\proxool-0.8.3.jar;X:\javaResources\sourceforge\hibernate\hibernate-3.2\lib\swarmcache-1.0rc2.jar;X:\javaResources\sourceforge\hibernate\hibernate-3.2\lib\syndiag2.jar;X:\javaResources\sourceforge\hibernate\hibernate-3.2\lib\versioncheck.jar;X:\javaResources\sourceforge\hibernate\hibernate-3.2\lib\xerces-2.6.2.jar;X:\javaResources\sourceforge\hibernate\hibernate-3.2\lib\xml-apis.jar;X:\javaResources\sourceforge\hsqldb\lib\hsqldb.jar;D:\Eclipse\newWorkspace2\DcsBase\bin;D:\Eclipse\newWorkspace2\DCSWebApp\EarContent\APP-INF\lib\hibernate3.jar;D:\Eclipse\newWorkspace2\DCSWebApp\EarContent\APP-INF\lib\spring.jar;D:\Eclipse\newWorkspace2\DCSWebApp\EarContent\APP-INF\lib\Address_R1_4_B8_20080514.jar;D:\Eclipse\newWorkspace2\DCSWebApp\EarContent\APP-INF\lib\BaseSecurity_R1_2_B1_20070314.jar;D:\Eclipse\newWorkspace2\DCSWebApp\EarContent\APP-INF\lib\BeaBaseSecurity_R1_1_B1_20070314.jar;D:\Eclipse\newWorkspace2\DCSWebApp\EarContent\APP-INF\lib\CommonLargeObjectLocal_R0_1_B3_20071229.jar;D:\Eclipse\newWorkspace2\DCSWebApp\EarContent\APP-INF\lib\CommonLargeObject_R0_1_B4_20080103.jar;D:\Eclipse\newWorkspace2\DCSWebApp\EarContent\APP-INF\lib\Common_R6_5_B1_20080514.jar;D:\Eclipse\newWorkspace2\DCSWebApp\EarContent\APP-INF\lib\CustodyAuthority_R1_2_B1_20050602.jar;D:\Eclipse\newWorkspace2\DCSWebApp\EarContent\APP-INF\lib\Custody_R1_5_B2.jar;D:\Eclipse\newWorkspace2\DCSWebApp\EarContent\APP-INF\lib\DCSCaseManagement_R1_0_B4.jar;D:\Eclipse\newWorkspace2\DCSWebApp\EarContent\APP-INF\lib\DCSCommunitySupervision_R1_0_B2.jar;D:\Eclipse\newWorkspace2\DCSWebApp\EarContent\APP-INF\lib\DCSSearch_R1_3_B3.jar;D:\Eclipse\newWorkspace2\DCSWebApp\EarContent\APP-INF\lib\DcsIncidentRecording_R1_1_B3.jar;D:\Eclipse\newWorkspace2\DCSWebApp\EarContent\APP-INF\lib\DcsIncident_R1_1_B15.jar;D:\Eclipse\newWorkspace2\DCSWebApp\EarContent\APP-INF\lib\Framework_R3_5_B2_20080513.jar;D:\Eclipse\newWorkspace2\DCSWebApp\EarContent\APP-INF\lib\Framework_TestHelper_R3_2_B6_20071231.jar;D:\Eclipse\newWorkspace2\DCSWebApp\EarContent\APP-INF\lib\JisCommon_weblogicR2.jar;D:\Eclipse\newWorkspace2\DCSWebApp\EarContent\APP-INF\lib\Mail_R1_4_B2.jar;D:\Eclipse\newWorkspace2\DCSWebApp\EarContent\APP-INF\lib\Party_R1_9_B1_20080514.jar;D:\Eclipse\newWorkspace2\DCSWebApp\EarContent\APP-INF\lib\PrisonerMail_R1_4_B2.jar;D:\Eclipse\newWorkspace2\DCSWebApp\EarContent\APP-INF\lib\PrisonerPhotos_R1_5_B1.jar;D:\Eclipse\newWorkspace2\DCSWebApp\EarContent\APP-INF\lib\Security_weblogicR2.jar;D:\Eclipse\newWorkspace2\DCSWebApp\EarContent\APP-INF\lib\Tidy.jar;D:\Eclipse\newWorkspace2\DCSWebApp\EarContent\APP-INF\lib\antlr-2.7.6.jar;D:\Eclipse\newWorkspace2\DCSWebApp\EarContent\APP-INF\lib\aspectjrt.jar;D:\Eclipse\newWorkspace2\DCSWebApp\EarContent\APP-INF\lib\aspectjweaver.jar;D:\Eclipse\newWorkspace2\DCSWebApp\EarContent\APP-INF\lib\avalon-framework-4.2.0.jar;D:\Eclipse\newWorkspace2\DCSWebApp\EarContent\APP-INF\lib\barcode4j-fop-ext-0.20.5-complete.jar;D:\Eclipse\newWorkspace2\DCSWebApp\EarContent\APP-INF\lib\batik.jar;D:\Eclipse\newWorkspace2\DCSWebApp\EarContent\APP-INF\lib\bsf-2.3.0.jar;D:\Eclipse\newWorkspace2\DCSWebApp\EarContent\APP-INF\lib\cglib-nodep-2.1_3.jar;D:\Eclipse\newWorkspace2\DCSWebApp\EarContent\APP-INF\lib\commons-beanutils.jar;D:\Eclipse\newWorkspace2\DCSWebApp\EarContent\APP-INF\lib\commons-collections-3.1.jar;D:\Eclipse\newWorkspace2\DCSWebApp\EarContent\APP-INF\lib\commons-dbcp-1.2.2.jar;D:\Eclipse\newWorkspace2\DCSWebApp\EarContent\APP-INF\lib\commons-digester.jar;D:\Eclipse\newWorkspace2\DCSWebApp\EarContent\APP-INF\lib\commons-fileupload-1.2.1.jar;D:\Eclipse\newWorkspace2\DCSWebApp\EarContent\APP-INF\lib\commons-io-1.4.jar;D:\Eclipse\newWorkspace2\DCSWebApp\EarContent\APP-INF\lib\commons-lang-2.2.jar;D:\Eclipse\newWorkspace2\DCSWebApp\EarContent\APP-INF\lib\commons-logging.jar;D:\Eclipse\newWorkspace2\DCSWebApp\EarContent\APP-INF\lib\commons-net-1.2.2.jar;D:\Eclipse\newWorkspace2\DCSWebApp\EarContent\APP-INF\lib\commons-pool-1.2.jar;D:\Eclipse\newWorkspace2\DCSWebApp\EarContent\APP-INF\lib\commons-resources.jar;D:\Eclipse\newWorkspace2\DCSWebApp\EarContent\APP-INF\lib\commons-services.jar;D:\Eclipse\newWorkspace2\DCSWebApp\EarContent\APP-INF\lib\commons-validator.jar;D:\Eclipse\newWorkspace2\DCSWebApp\EarContent\APP-INF\lib\displaytag-1.1.1.jar;D:\Eclipse\newWorkspace2\DCSWebApp\EarContent\APP-INF\lib\dom4j-1.6.1.jar;D:\Eclipse\newWorkspace2\DCSWebApp\EarContent\APP-INF\lib\dwr.jar;D:\Eclipse\newWorkspace2\DCSWebApp\EarContent\APP-INF\lib\ehcache-1.1.jar;D:\Eclipse\newWorkspace2\DCSWebApp\EarContent\APP-INF\lib\fop.jar;D:\Eclipse\newWorkspace2\DCSWebApp\EarContent\APP-INF\lib\glassfish-clapi.jar;D:\Eclipse\newWorkspace2\DCSWebApp\EarContent\APP-INF\lib\hibernate-annotations.jar;D:\Eclipse\newWorkspace2\DCSWebApp\EarContent\APP-INF\lib\hibernate-search.jar;D:\Eclipse\newWorkspace2\DCSWebApp\EarContent\APP-INF\lib\hibernate2.jar;D:\Eclipse\newWorkspace2\DCSWebApp\EarContent\APP-INF\lib\hibernate3.jar;D:\Eclipse\newWorkspace2\DCSWebApp\EarContent\APP-INF\lib\idmsjdbc.jar;D:\Eclipse\newWorkspace2\DCSWebApp\EarContent\APP-INF\lib\itext.jar;D:\Eclipse\newWorkspace2\DCSWebApp\EarContent\APP-INF\lib\j2ee.jar;D:\Eclipse\newWorkspace2\DCSWebApp\EarContent\APP-INF\lib\jai_codec.jar;D:\Eclipse\newWorkspace2\DCSWebApp\EarContent\APP-INF\lib\jai_core.jar;D:\Eclipse\newWorkspace2\DCSWebApp\EarContent\APP-INF\lib\jakarta-oro.jar;D:\Eclipse\newWorkspace2\DCSWebApp\EarContent\APP-INF\lib\jamon-2.4.jar;D:\Eclipse\newWorkspace2\DCSWebApp\EarContent\APP-INF\lib\jaxen-1.1-beta-7.jar;D:\Eclipse\newWorkspace2\DCSWebApp\EarContent\APP-INF\lib\jcs-1.0-dev.jar;D:\Eclipse\newWorkspace2\DCSWebApp\EarContent\APP-INF\lib\jdom-1.jar;D:\Eclipse\newWorkspace2\DCSWebApp\EarContent\APP-INF\lib\jimi-1.0.jar;D:\Eclipse\newWorkspace2\DCSWebApp\EarContent\APP-INF\lib\jmock-1.1.0RC1.jar;D:\Eclipse\newWorkspace2\DCSWebApp\EarContent\APP-INF\lib\js.jar;D:\Eclipse\newWorkspace2\DCSWebApp\EarContent\APP-INF\lib\jspbook.jar;D:\Eclipse\newWorkspace2\DCSWebApp\EarContent\APP-INF\lib\jstl.jar;D:\Eclipse\newWorkspace2\DCSWebApp\EarContent\APP-INF\lib\jtds.jar;D:\Eclipse\newWorkspace2\DCSWebApp\EarContent\APP-INF\lib\junit.jar;D:\Eclipse\newWorkspace2\DCSWebApp\EarContent\APP-INF\lib\ldap.jar;D:\Eclipse\newWorkspace2\DCSWebApp\EarContent\APP-INF\lib\log4j-1.2.15.jar;D:\Eclipse\newWorkspace2\DCSWebApp\EarContent\APP-INF\lib\lucene-core-2.2.0.jar;D:\Eclipse\newWorkspace2\DCSWebApp\EarContent\APP-INF\lib\odmg-3.0.jar;D:\Eclipse\newWorkspace2\DCSWebApp\EarContent\APP-INF\lib\ognl-2.6.9.jar;D:\Eclipse\newWorkspace2\DCSWebApp\EarContent\APP-INF\lib\ojdbc14.jar;D:\Eclipse\newWorkspace2\DCSWebApp\EarContent\APP-INF\lib\org.springframework.binding-2.0.1.RELEASE.jar;D:\Eclipse\newWorkspace2\DCSWebApp\EarContent\APP-INF\lib\org.springframework.js-2.0.1.RELEASE.jar;D:\Eclipse\newWorkspace2\DCSWebApp\EarContent\APP-INF\lib\org.springframework.webflow-2.0.1.RELEASE.jar;D:\Eclipse\newWorkspace2\DCSWebApp\EarContent\APP-INF\lib\oro-2.0.8.jar;D:\Eclipse\newWorkspace2\DCSWebApp\EarContent\APP-INF\lib\pdf-transcoder.jar;D:\Eclipse\newWorkspace2\DCSWebApp\EarContent\APP-INF\lib\quartz.jar;D:\Eclipse\newWorkspace2\DCSWebApp\EarContent\APP-INF\lib\serializer-2.7.0.jar;D:\Eclipse\newWorkspace2\DCSWebApp\EarContent\APP-INF\lib\slf4j-api-1.4.2.jar;D:\Eclipse\newWorkspace2\DCSWebApp\EarContent\APP-INF\lib\slf4j-log4j12-1.5.0.jar;D:\Eclipse\newWorkspace2\DCSWebApp\EarContent\APP-INF\lib\spring-test.jar;D:\Eclipse\newWorkspace2\DCSWebApp\EarContent\APP-INF\lib\spring-web.jar;D:\Eclipse\newWorkspace2\DCSWebApp\EarContent\APP-INF\lib\spring-webmvc-portlet.jar;D:\Eclipse\newWorkspace2\DCSWebApp\EarContent\APP-INF\lib\spring-webmvc.jar;D:\Eclipse\newWorkspace2\DCSWebApp\EarContent\APP-INF\lib\spring.jar;D:\Eclipse\newWorkspace2\DCSWebApp\EarContent\APP-INF\lib\standard.jar;D:\Eclipse\newWorkspace2\DCSWebApp\EarContent\APP-INF\lib\struts-menu-2.3.jar;D:\Eclipse\newWorkspace2\DCSWebApp\EarContent\APP-INF\lib\struts-menu-2.4.3.jar;D:\Eclipse\newWorkspace2\DCSWebApp\EarContent\APP-INF\lib\struts.jar;D:\Eclipse\newWorkspace2\DCSWebApp\EarContent\APP-INF\lib\strutstest-2.1.2.jar;D:\Eclipse\newWorkspace2\DCSWebApp\EarContent\APP-INF\lib\velocity.jar;D:\Eclipse\newWorkspace2\DCSWebApp\EarContent\APP-INF\classes;/C:/bea10.2/tools/eclipse_pkgs/1.1/eclipse_3.2.2/eclipse/plugins/org.eclipse.jdt.junit_3.2.1.r321_v20060810/junitsupport.jar;/C:/bea10.2/tools/eclipse_pkgs/1.1/eclipse_3.2.2/eclipse/plugins/org.eclipse.jdt.junit.runtime_3.2.1.r321_v20060721/junitruntime.jar, user.name=conttl, hibernate.bytecode.use_reflection_optimizer=false, hibernate.show_sql=true, java.vm.specification.version=1.0, sun.arch.data.model=32, java.home=C:\bea10.2\jdk150_11\jre, hibernate.dialect=org.hibernate.dialect.HSQLDialect, hibernate.connection.url=jdbc:hsqldb:mem:baseball, java.specification.vendor=Sun Microsystems Inc., user.language=en, awt.toolkit=sun.awt.windows.WToolkit, java.vm.info=mixed mode, java.version=1.5.0_11, java.ext.dirs=C:\bea10.2\jdk150_11\jre\lib\ext, sun.boot.class.path=C:\bea10.2\jdk150_11\jre\lib\rt.jar;C:\bea10.2\jdk150_11\jre\lib\jsse.jar;C:\bea10.2\jdk150_11\jre\lib\jce.jar;C:\bea10.2\jdk150_11\jre\lib\charsets.jar, java.vendor=Sun Microsystems Inc., file.separator=\, java.vendor.url.bug=http://java.sun.com/cgi-bin/bugreport.cgi, hibernate.hbm2ddl.auto=create-drop, sun.cpu.endian=little, sun.io.unicode.encoding=UnicodeLittle, sun.desktop=windows, sun.cpu.isalist=}
2008-05-21 14:32:43,185 DEBUG AbstractEntityPersister :: main :: Static SQL for entity: Cat
2008-05-21 14:32:43,185 DEBUG AbstractEntityPersister :: main :: Version select: select version from Cat where id =?
2008-05-21 14:32:43,185 DEBUG AbstractEntityPersister :: main :: Snapshot select: select cat_.id, cat_.version as version0_, cat_.name as name0_, cat_.type as type0_ from Cat cat_ where cat_.id=?
2008-05-21 14:32:43,185 DEBUG AbstractEntityPersister :: main :: Insert 0: insert into Cat (version, name, type, id) values (?, ?, ?, ?)
2008-05-21 14:32:43,185 DEBUG AbstractEntityPersister :: main :: Update 0: update Cat set version=?, name=?, type=? where id=? and version=?
2008-05-21 14:32:43,185 DEBUG AbstractEntityPersister :: main :: Delete 0: delete from Cat where id=? and version=?
2008-05-21 14:32:43,185 DEBUG AbstractEntityPersister :: main :: Static SQL for entity: CatHistory
2008-05-21 14:32:43,185 DEBUG AbstractEntityPersister :: main :: Version select: select id, version from CatHist where id =? and version =?
2008-05-21 14:32:43,185 DEBUG AbstractEntityPersister :: main :: Snapshot select: select cathistory_.id, cathistory_.version, cathistory_.name as name2_, cathistory_.type as type2_ from CatHist cathistory_ where cathistory_.id=? and cathistory_.version=?
2008-05-21 14:32:43,185 DEBUG AbstractEntityPersister :: main :: Insert 0: insert into CatHist (name, type, id, version) values (?, ?, ?, ?)
2008-05-21 14:32:43,185 DEBUG AbstractEntityPersister :: main :: Update 0: update CatHist set name=?, type=? where id=? and version=?
2008-05-21 14:32:43,185 DEBUG AbstractEntityPersister :: main :: Delete 0: delete from CatHist where id=? and version=?
2008-05-21 14:32:43,201 DEBUG AbstractCollectionPersister :: main :: Static SQL for collection: Cat.mice
2008-05-21 14:32:43,201 DEBUG AbstractCollectionPersister :: main :: Row insert: insert into Mouse (cat, rabid, description, species) values (?, ?, ?, ?)
2008-05-21 14:32:43,201 DEBUG AbstractCollectionPersister :: main :: Row update: update Mouse set rabid=?, description=?, species=? where cat=? and rabid=? and description=? and species=?
2008-05-21 14:32:43,201 DEBUG AbstractCollectionPersister :: main :: Row delete: delete from Mouse where cat=? and rabid=? and description=? and species=?
2008-05-21 14:32:43,201 DEBUG AbstractCollectionPersister :: main :: One-shot delete: delete from Mouse where cat=?
2008-05-21 14:32:43,201 DEBUG AbstractCollectionPersister :: main :: Static SQL for collection: CatHistory.mice
2008-05-21 14:32:43,201 DEBUG AbstractCollectionPersister :: main :: Row insert: insert into MouseHist (cat, version, rabid, description, species) values (?, ?, ?, ?, ?)
2008-05-21 14:32:43,201 DEBUG AbstractCollectionPersister :: main :: Row update: update MouseHist set rabid=?, description=?, species=? where cat=? and version=? and rabid=? and description=? and species=?
2008-05-21 14:32:43,201 DEBUG AbstractCollectionPersister :: main :: Row delete: delete from MouseHist where cat=? and version=? and rabid=? and description=? and species=?
2008-05-21 14:32:43,201 DEBUG AbstractCollectionPersister :: main :: One-shot delete: delete from MouseHist where cat=? and version=?
2008-05-21 14:32:43,232 DEBUG EntityLoader :: main :: Static select for entity Cat: select cat0_.id as id0_0_, cat0_.version as version0_0_, cat0_.name as name0_0_, cat0_.type as type0_0_ from Cat cat0_ where cat0_.id=?
2008-05-21 14:32:43,232 DEBUG EntityLoader :: main :: Static select for entity Cat: select cat0_.id as id0_0_, cat0_.version as version0_0_, cat0_.name as name0_0_, cat0_.type as type0_0_ from Cat cat0_ where cat0_.id=?
2008-05-21 14:32:43,248 DEBUG EntityLoader :: main :: Static select for entity Cat: select cat0_.id as id0_0_, cat0_.version as version0_0_, cat0_.name as name0_0_, cat0_.type as type0_0_ from Cat cat0_ where cat0_.id=?
2008-05-21 14:32:43,248 DEBUG EntityLoader :: main :: Static select for entity Cat: select cat0_.id as id0_0_, cat0_.version as version0_0_, cat0_.name as name0_0_, cat0_.type as type0_0_ from Cat cat0_ where cat0_.id=?
2008-05-21 14:32:43,248 DEBUG EntityLoader :: main :: Static select for entity Cat: select cat0_.id as id0_0_, cat0_.version as version0_0_, cat0_.name as name0_0_, cat0_.type as type0_0_ from Cat cat0_ where cat0_.id=?
2008-05-21 14:32:43,248 DEBUG EntityLoader :: main :: Static select for action ACTION_MERGE on entity Cat: select cat0_.id as id0_0_, cat0_.version as version0_0_, cat0_.name as name0_0_, cat0_.type as type0_0_ from Cat cat0_ where cat0_.id=?
2008-05-21 14:32:43,248 DEBUG EntityLoader :: main :: Static select for action ACTION_REFRESH on entity Cat: select cat0_.id as id0_0_, cat0_.version as version0_0_, cat0_.name as name0_0_, cat0_.type as type0_0_ from Cat cat0_ where cat0_.id=?
2008-05-21 14:32:43,248 DEBUG EntityLoader :: main :: Static select for entity CatHistory: select cathistory0_.id as id2_0_, cathistory0_.version as version2_0_, cathistory0_.name as name2_0_, cathistory0_.type as type2_0_ from CatHist cathistory0_ where cathistory0_.id=? and cathistory0_.version=?
2008-05-21 14:32:43,248 DEBUG EntityLoader :: main :: Static select for entity CatHistory: select cathistory0_.id as id2_0_, cathistory0_.version as version2_0_, cathistory0_.name as name2_0_, cathistory0_.type as type2_0_ from CatHist cathistory0_ where cathistory0_.id=? and cathistory0_.version=?
2008-05-21 14:32:43,248 DEBUG EntityLoader :: main :: Static select for entity CatHistory: select cathistory0_.id as id2_0_, cathistory0_.version as version2_0_, cathistory0_.name as name2_0_, cathistory0_.type as type2_0_ from CatHist cathistory0_ where cathistory0_.id=? and cathistory0_.version=?
2008-05-21 14:32:43,248 DEBUG EntityLoader :: main :: Static select for entity CatHistory: select cathistory0_.id as id2_0_, cathistory0_.version as version2_0_, cathistory0_.name as name2_0_, cathistory0_.type as type2_0_ from CatHist cathistory0_ where cathistory0_.id=? and cathistory0_.version=?
2008-05-21 14:32:43,248 DEBUG EntityLoader :: main :: Static select for entity CatHistory: select cathistory0_.id as id2_0_, cathistory0_.version as version2_0_, cathistory0_.name as name2_0_, cathistory0_.type as type2_0_ from CatHist cathistory0_ where cathistory0_.id=? and cathistory0_.version=?
2008-05-21 14:32:43,248 DEBUG EntityLoader :: main :: Static select for action ACTION_MERGE on entity CatHistory: select cathistory0_.id as id2_0_, cathistory0_.version as version2_0_, cathistory0_.name as name2_0_, cathistory0_.type as type2_0_ from CatHist cathistory0_ where cathistory0_.id=? and cathistory0_.version=?
2008-05-21 14:32:43,248 DEBUG EntityLoader :: main :: Static select for action ACTION_REFRESH on entity CatHistory: select cathistory0_.id as id2_0_, cathistory0_.version as version2_0_, cathistory0_.name as name2_0_, cathistory0_.type as type2_0_ from CatHist cathistory0_ where cathistory0_.id=? and cathistory0_.version=?
2008-05-21 14:32:43,263 DEBUG BasicCollectionLoader :: main :: Static select for collection Cat.mice: select mice0_.cat as cat0_, mice0_.rabid as rabid0_, mice0_.description as descript3_0_, mice0_.species as species0_ from Mouse mice0_ where mice0_.cat=? order by mice0_.description
2008-05-21 14:32:43,263 DEBUG BasicCollectionLoader :: main :: Static select for collection CatHistory.mice: select mice0_.cat as cat0_, mice0_.version as version0_, mice0_.rabid as rabid0_, mice0_.description as descript4_0_, mice0_.species as species0_ from MouseHist mice0_ where mice0_.cat=? and mice0_.version=? order by mice0_.description
2008-05-21 14:32:43,263 DEBUG SessionFactoryObjectFactory :: main :: initializing class SessionFactoryObjectFactory
2008-05-21 14:32:43,263 DEBUG SessionFactoryObjectFactory :: main :: registered: 8aebbfa21a09db94011a09db963f0000 (unnamed)
2008-05-21 14:32:43,263 INFO SessionFactoryObjectFactory :: main :: Not binding factory to JNDI, no JNDI name configured
2008-05-21 14:32:43,263 DEBUG SessionFactoryImpl :: main :: instantiated session factory
2008-05-21 14:32:43,279 DEBUG Configuration :: main :: processing extends queue
2008-05-21 14:32:43,279 DEBUG Configuration :: main :: processing collection mappings
2008-05-21 14:32:43,279 DEBUG Configuration :: main :: processing native query and ResultSetMapping mappings
2008-05-21 14:32:43,279 DEBUG Configuration :: main :: processing association property references
2008-05-21 14:32:43,279 DEBUG Configuration :: main :: processing foreign key constraints
2008-05-21 14:32:43,279 DEBUG Configuration :: main :: resolving reference to class: Cat
2008-05-21 14:32:43,279 DEBUG Configuration :: main :: resolving reference to class: CatHistory
2008-05-21 14:32:43,279 DEBUG Configuration :: main :: processing extends queue
2008-05-21 14:32:43,279 DEBUG Configuration :: main :: processing collection mappings
2008-05-21 14:32:43,279 DEBUG Configuration :: main :: processing native query and ResultSetMapping mappings
2008-05-21 14:32:43,279 DEBUG Configuration :: main :: processing association property references
2008-05-21 14:32:43,279 DEBUG Configuration :: main :: processing foreign key constraints
2008-05-21 14:32:43,279 DEBUG Configuration :: main :: resolving reference to class: Cat
2008-05-21 14:32:43,279 DEBUG Configuration :: main :: resolving reference to class: CatHistory
2008-05-21 14:32:43,279 INFO SchemaExport :: main :: Running hbm2ddl schema export
2008-05-21 14:32:43,279 DEBUG SchemaExport :: main :: import file not found: /import.sql
2008-05-21 14:32:43,279 INFO SchemaExport :: main :: exporting generated schema to database
2008-05-21 14:32:43,279 DEBUG DriverManagerConnectionProvider :: main :: total checked-out connections: 0
2008-05-21 14:32:43,279 DEBUG DriverManagerConnectionProvider :: main :: using pooled JDBC connection, pool size: 0
2008-05-21 14:32:43,279 DEBUG SchemaExport :: main :: alter table Mouse drop constraint FK4714C852878C
2008-05-21 14:32:43,279 DEBUG SchemaExport :: main :: Unsuccessful: alter table Mouse drop constraint FK4714C852878C
2008-05-21 14:32:43,279 DEBUG SchemaExport :: main :: Table not found: MOUSE in statement [alter table Mouse]
2008-05-21 14:32:43,279 DEBUG SchemaExport :: main :: alter table MouseHist drop constraint FK9A5FD547DE9E18AC
2008-05-21 14:32:43,279 DEBUG SchemaExport :: main :: Unsuccessful: alter table MouseHist drop constraint FK9A5FD547DE9E18AC
2008-05-21 14:32:43,279 DEBUG SchemaExport :: main :: Table not found: MOUSEHIST in statement [alter table MouseHist]
2008-05-21 14:32:43,279 DEBUG SchemaExport :: main :: drop table Cat if exists
2008-05-21 14:32:43,279 DEBUG SchemaExport :: main :: drop table CatHist if exists
2008-05-21 14:32:43,279 DEBUG SchemaExport :: main :: drop table Mouse if exists
2008-05-21 14:32:43,279 DEBUG SchemaExport :: main :: drop table MouseHist if exists
2008-05-21 14:32:43,279 DEBUG SchemaExport :: main :: drop table hibernate_unique_key if exists
2008-05-21 14:32:43,279 DEBUG SchemaExport :: main :: create table Cat (id bigint not null, version bigint not null, name varchar(255), type varchar(255), primary key (id))
2008-05-21 14:32:43,294 DEBUG SchemaExport :: main :: create table CatHist (id bigint not null, version bigint not null, name varchar(255), type varchar(255), primary key (id, version))
2008-05-21 14:32:43,294 DEBUG SchemaExport :: main :: create table Mouse (cat bigint not null, rabid bit, description varchar(255), species varchar(255))
2008-05-21 14:32:43,294 DEBUG SchemaExport :: main :: create table MouseHist (cat bigint not null, version bigint not null, rabid bit, description varchar(255), species varchar(255))
2008-05-21 14:32:43,294 DEBUG SchemaExport :: main :: alter table Mouse add constraint FK4714C852878C foreign key (cat) references Cat
2008-05-21 14:32:43,294 DEBUG SchemaExport :: main :: alter table MouseHist add constraint FK9A5FD547DE9E18AC foreign key (cat, version) references CatHist
2008-05-21 14:32:43,294 DEBUG SchemaExport :: main :: create table hibernate_unique_key ( next_hi integer )
2008-05-21 14:32:43,294 DEBUG SchemaExport :: main :: insert into hibernate_unique_key values ( 0 )
2008-05-21 14:32:43,294 INFO SchemaExport :: main :: schema export complete
2008-05-21 14:32:43,294 DEBUG DriverManagerConnectionProvider :: main :: returning connection to pool, pool size: 1
2008-05-21 14:32:43,294 DEBUG Configuration :: main :: processing extends queue
2008-05-21 14:32:43,294 DEBUG Configuration :: main :: processing collection mappings
2008-05-21 14:32:43,294 DEBUG Configuration :: main :: processing native query and ResultSetMapping mappings
2008-05-21 14:32:43,294 DEBUG Configuration :: main :: processing association property references
2008-05-21 14:32:43,310 DEBUG Configuration :: main :: processing foreign key constraints
2008-05-21 14:32:43,310 DEBUG Configuration :: main :: resolving reference to class: Cat
2008-05-21 14:32:43,310 DEBUG Configuration :: main :: resolving reference to class: CatHistory
2008-05-21 14:32:43,310 DEBUG Configuration :: main :: processing extends queue
2008-05-21 14:32:43,310 DEBUG Configuration :: main :: processing collection mappings
2008-05-21 14:32:43,310 DEBUG Configuration :: main :: processing native query and ResultSetMapping mappings
2008-05-21 14:32:43,310 DEBUG Configuration :: main :: processing association property references
2008-05-21 14:32:43,310 DEBUG Configuration :: main :: processing foreign key constraints
2008-05-21 14:32:43,310 DEBUG Configuration :: main :: resolving reference to class: Cat
2008-05-21 14:32:43,310 DEBUG Configuration :: main :: resolving reference to class: CatHistory
2008-05-21 14:32:43,310 DEBUG SessionFactoryImpl :: main :: Checking 0 named HQL queries
2008-05-21 14:32:43,310 DEBUG SessionFactoryImpl :: main :: Checking 0 named SQL queries
2008-05-21 14:32:43,373 DEBUG SessionImpl :: main :: opened session at timestamp: 4961673884917760
2008-05-21 14:32:43,373 DEBUG JDBCTransaction :: main :: begin
2008-05-21 14:32:43,373 DEBUG ConnectionManager :: main :: opening JDBC connection
2008-05-21 14:32:43,373 DEBUG DriverManagerConnectionProvider :: main :: total checked-out connections: 0
2008-05-21 14:32:43,373 DEBUG DriverManagerConnectionProvider :: main :: using pooled JDBC connection, pool size: 0
2008-05-21 14:32:43,373 DEBUG JDBCTransaction :: main :: current autocommit status: true
2008-05-21 14:32:43,373 DEBUG JDBCTransaction :: main :: disabling autocommit
2008-05-21 14:32:43,373 DEBUG JDBCContext :: main :: after transaction begin
2008-05-21 14:32:43,373 DEBUG DefaultSaveOrUpdateEventListener :: main :: saving transient instance
2008-05-21 14:32:43,388 DEBUG AbstractBatcher :: main :: opening JDBC connection
2008-05-21 14:32:43,388 DEBUG DriverManagerConnectionProvider :: main :: total checked-out connections: 1
2008-05-21 14:32:43,388 DEBUG DriverManagerConnectionProvider :: main :: opening new JDBC connection
2008-05-21 14:32:43,388 DEBUG DriverManagerConnectionProvider :: main :: created connection to: jdbc:hsqldb:mem:baseball, Isolation Level: 2
2008-05-21 14:32:43,388 DEBUG SQL :: main :: select next_hi from hibernate_unique_key
2008-05-21 14:32:43,404 DEBUG SQL :: main :: update hibernate_unique_key set next_hi = ? where next_hi = ?
2008-05-21 14:32:43,404 DEBUG AbstractBatcher :: main :: closing JDBC connection (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)
2008-05-21 14:32:43,404 DEBUG DriverManagerConnectionProvider :: main :: returning connection to pool, pool size: 1
2008-05-21 14:32:43,404 DEBUG TableHiLoGenerator :: main :: new hi value: 0
2008-05-21 14:32:43,404 DEBUG AbstractSaveEventListener :: main :: generated identifier: 1, using strategy: org.hibernate.id.TableHiLoGenerator
2008-05-21 14:32:43,404 DEBUG AbstractSaveEventListener :: main :: saving [Cat#1]
2008-05-21 14:32:43,419 DEBUG Versioning :: main :: using initial version: 1
2008-05-21 14:32:43,435 DEBUG WrapVisitor :: main :: Wrapped collection in role: Cat.mice
2008-05-21 14:32:43,451 DEBUG AbstractFlushingEventListener :: main :: flushing session
2008-05-21 14:32:43,451 DEBUG AbstractFlushingEventListener :: main :: processing flush-time cascades
2008-05-21 14:32:43,451 DEBUG AbstractFlushingEventListener :: main :: dirty checking collections
2008-05-21 14:32:43,451 DEBUG AbstractFlushingEventListener :: main :: Flushing entities and processing referenced collections
2008-05-21 14:32:43,451 DEBUG Collections :: main :: Collection found: [Cat.mice#1], was: [<unreferenced>] (initialized)
2008-05-21 14:32:43,451 DEBUG AbstractFlushingEventListener :: main :: Processing unreferenced collections
2008-05-21 14:32:43,451 DEBUG AbstractFlushingEventListener :: main :: Scheduling collection removes/(re)creates/updates
2008-05-21 14:32:43,451 DEBUG AbstractFlushingEventListener :: main :: Flushed: 1 insertions, 0 updates, 0 deletions to 1 objects
2008-05-21 14:32:43,451 DEBUG AbstractFlushingEventListener :: main :: Flushed: 1 (re)creations, 0 updates, 0 removals to 1 collections
2008-05-21 14:32:43,498 DEBUG Printer :: main :: listing entities:
2008-05-21 14:32:43,498 DEBUG Printer :: main :: test.hib3local.CatEntity
2008-05-21 14:32:43,498 DEBUG AbstractFlushingEventListener :: main :: executing flush
2008-05-21 14:32:43,498 DEBUG ConnectionManager :: main :: registering flush begin
2008-05-21 14:32:43,498 DEBUG AbstractEntityPersister :: main :: Inserting entity: [Cat#1]
2008-05-21 14:32:43,498 DEBUG AbstractEntityPersister :: main :: Version: 1
2008-05-21 14:32:43,498 DEBUG AbstractBatcher :: main :: about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
2008-05-21 14:32:43,498 DEBUG SQL :: main :: insert into Cat (version, name, type, id) values (?, ?, ?, ?)
2008-05-21 14:32:43,498 DEBUG AbstractBatcher :: main :: preparing statement
2008-05-21 14:32:43,498 DEBUG AbstractEntityPersister :: main :: Dehydrating entity: [Cat#1]
2008-05-21 14:32:43,498 DEBUG LongType :: main :: binding '1' to parameter: 1
2008-05-21 14:32:43,498 DEBUG StringType :: main :: binding 'Miffy' to parameter: 2
2008-05-21 14:32:43,498 DEBUG StringType :: main :: binding 'Tabby' to parameter: 3
2008-05-21 14:32:43,498 DEBUG LongType :: main :: binding '1' to parameter: 4
2008-05-21 14:32:43,498 DEBUG AbstractBatcher :: main :: Executing batch size: 1
2008-05-21 14:32:43,498 DEBUG AbstractBatcher :: main :: about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
2008-05-21 14:32:43,498 DEBUG AbstractBatcher :: main :: closing statement
2008-05-21 14:32:43,498 DEBUG AbstractCollectionPersister :: main :: Inserting collection: [Cat.mice#1]
2008-05-21 14:32:43,498 DEBUG AbstractBatcher :: main :: about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
2008-05-21 14:32:43,498 DEBUG SQL :: main :: insert into Mouse (cat, rabid, description, species) values (?, ?, ?, ?)
2008-05-21 14:32:43,498 DEBUG AbstractBatcher :: main :: preparing statement
2008-05-21 14:32:43,498 DEBUG LongType :: main :: binding '1' to parameter: 1
2008-05-21 14:32:43,498 DEBUG BooleanType :: main :: binding 'false' to parameter: 2
2008-05-21 14:32:43,498 DEBUG StringType :: main :: binding 'A' to parameter: 3
2008-05-21 14:32:43,498 DEBUG StringType :: main :: binding null to parameter: 4
2008-05-21 14:32:43,498 DEBUG AbstractCollectionPersister :: main :: done inserting collection: 1 rows inserted
2008-05-21 14:32:43,498 DEBUG AbstractBatcher :: main :: Executing batch size: 1
2008-05-21 14:32:43,498 DEBUG AbstractBatcher :: main :: about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
2008-05-21 14:32:43,498 DEBUG AbstractBatcher :: main :: closing statement
2008-05-21 14:32:43,498 DEBUG ConnectionManager :: main :: registering flush end
2008-05-21 14:32:43,498 DEBUG AbstractFlushingEventListener :: main :: post flush
2008-05-21 14:32:43,498 DEBUG DefaultLoadEventListener :: main :: loading entity: [Cat#1]
2008-05-21 14:32:43,498 DEBUG DefaultLoadEventListener :: main :: entity found in session cache
2008-05-21 14:32:43,498 DEBUG DefaultSaveOrUpdateEventListener :: main :: ignoring persistent instance
2008-05-21 14:32:43,498 DEBUG DefaultSaveOrUpdateEventListener :: main :: object already associated with session: [Cat#1]
2008-05-21 14:32:43,498 DEBUG AbstractFlushingEventListener :: main :: flushing session
2008-05-21 14:32:43,498 DEBUG AbstractFlushingEventListener :: main :: processing flush-time cascades
2008-05-21 14:32:43,498 DEBUG AbstractFlushingEventListener :: main :: dirty checking collections
2008-05-21 14:32:43,498 DEBUG CollectionEntry :: main :: Collection dirty: [Cat.mice#1]
2008-05-21 14:32:43,498 DEBUG AbstractFlushingEventListener :: main :: Flushing entities and processing referenced collections
2008-05-21 14:32:43,498 DEBUG AbstractEntityPersister :: main :: Cat.name is dirty
2008-05-21 14:32:43,498 DEBUG AbstractEntityPersister :: main :: Cat.type is dirty
2008-05-21 14:32:43,498 DEBUG DefaultFlushEntityEventListener :: main :: Updating entity: [Cat#1]
2008-05-21 14:32:43,498 DEBUG Versioning :: main :: Incrementing: 1 to 2
2008-05-21 14:32:43,498 DEBUG Collections :: main :: Collection found: [Cat.mice#1], was: [Cat.mice#1] (initialized)
2008-05-21 14:32:43,498 DEBUG AbstractFlushingEventListener :: main :: Processing unreferenced collections
2008-05-21 14:32:43,498 DEBUG AbstractFlushingEventListener :: main :: Scheduling collection removes/(re)creates/updates
2008-05-21 14:32:43,498 DEBUG AbstractFlushingEventListener :: main :: Flushed: 0 insertions, 1 updates, 0 deletions to 1 objects
2008-05-21 14:32:43,498 DEBUG AbstractFlushingEventListener :: main :: Flushed: 0 (re)creations, 1 updates, 0 removals to 1 collections
2008-05-21 14:32:43,498 DEBUG Printer :: main :: listing entities:
2008-05-21 14:32:43,498 DEBUG Printer :: main :: test.hib3local.CatEntity
2008-05-21 14:32:43,498 DEBUG AbstractFlushingEventListener :: main :: executing flush
2008-05-21 14:32:43,498 DEBUG ConnectionManager :: main :: registering flush begin
2008-05-21 14:32:43,498 DEBUG HistoryEventListener :: main :: *** saveHistoryEntity(CatEntity, 1)
2008-05-21 14:32:43,544 DEBUG SessionImpl :: main :: opened session at timestamp: -9223372036854775808
2008-05-21 14:32:43,544 DEBUG SessionImpl :: main :: setting cache mode to: IGNORE
2008-05-21 14:32:43,544 DEBUG SessionImpl :: main :: setting flush mode to: MANUAL
2008-05-21 14:32:43,544 DEBUG DefaultLoadEventListener :: main :: loading entity: [Cat#1]
2008-05-21 14:32:43,544 DEBUG DefaultLoadEventListener :: main :: creating new proxy for entity
2008-05-21 14:32:43,544 DEBUG JDBCContext :: main :: after autocommit
2008-05-21 14:32:43,544 DEBUG ConnectionManager :: main :: transaction completed on session with on_close connection release mode; be sure to close the session to release JDBC resources!
2008-05-21 14:32:43,544 DEBUG SessionImpl :: main :: initializing proxy: [Cat#1]
2008-05-21 14:32:43,544 DEBUG DefaultLoadEventListener :: main :: attempting to resolve: [Cat#1]
2008-05-21 14:32:43,544 DEBUG DefaultLoadEventListener :: main :: object not resolved in any cache: [Cat#1]
2008-05-21 14:32:43,544 DEBUG AbstractEntityPersister :: main :: Fetching entity: [Cat#1]
2008-05-21 14:32:43,544 DEBUG Loader :: main :: loading entity: [Cat#1]
2008-05-21 14:32:43,544 DEBUG AbstractBatcher :: main :: about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
2008-05-21 14:32:43,544 DEBUG SQL :: main :: select cat0_.id as id0_0_, cat0_.version as version0_0_, cat0_.name as name0_0_, cat0_.type as type0_0_ from Cat cat0_ where cat0_.id=?
2008-05-21 14:32:43,544 DEBUG AbstractBatcher :: main :: preparing statement
2008-05-21 14:32:43,560 DEBUG LongType :: main :: binding '1' to parameter: 1
2008-05-21 14:32:43,560 DEBUG AbstractBatcher :: main :: about to open ResultSet (open ResultSets: 0, globally: 0)
2008-05-21 14:32:43,560 DEBUG Loader :: main :: processing result set
2008-05-21 14:32:43,560 DEBUG Loader :: main :: result set row: 0
2008-05-21 14:32:43,560 DEBUG Loader :: main :: result row: EntityKey[Cat#1]
2008-05-21 14:32:43,560 DEBUG Loader :: main :: Initializing object from ResultSet: [Cat#1]
2008-05-21 14:32:43,560 DEBUG AbstractEntityPersister :: main :: Hydrating entity: [Cat#1]
2008-05-21 14:32:43,560 DEBUG LongType :: main :: returning '1' as column: version0_0_
2008-05-21 14:32:43,560 DEBUG StringType :: main :: returning 'Miffy' as column: name0_0_
2008-05-21 14:32:43,560 DEBUG StringType :: main :: returning 'Tabby' as column: type0_0_
2008-05-21 14:32:43,560 DEBUG TwoPhaseLoad :: main :: Version: 1
2008-05-21 14:32:43,560 DEBUG Loader :: main :: done processing result set (1 rows)
2008-05-21 14:32:43,576 DEBUG AbstractBatcher :: main :: about to close ResultSet (open ResultSets: 1, globally: 1)
2008-05-21 14:32:43,576 DEBUG AbstractBatcher :: main :: about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
2008-05-21 14:32:43,576 DEBUG AbstractBatcher :: main :: closing statement
2008-05-21 14:32:43,576 DEBUG Loader :: main :: total objects hydrated: 1
2008-05-21 14:32:43,576 DEBUG TwoPhaseLoad :: main :: resolving associations for [Cat#1]
2008-05-21 14:32:43,576 DEBUG LoadContexts :: main :: creating collection wrapper:[Cat.mice#1]
2008-05-21 14:32:43,576 DEBUG TwoPhaseLoad :: main :: done materializing entity [Cat#1]
2008-05-21 14:32:43,576 DEBUG StatefulPersistenceContext :: main :: initializing non-lazy collections
2008-05-21 14:32:43,576 DEBUG Loader :: main :: done entity load
2008-05-21 14:32:43,576 DEBUG DefaultEvictEventListener :: main :: evicting [Cat]
2008-05-21 14:32:43,576 DEBUG EvictVisitor :: main :: evicting collection: [Cat.mice#1]
2008-05-21 14:32:43,591 DEBUG DefaultSaveOrUpdateEventListener :: main :: saving transient instance
2008-05-21 14:32:43,591 DEBUG AbstractSaveEventListener :: main :: generated identifier: component[id,version]{id=1, version=1}, using strategy: org.hibernate.id.Assigned
2008-05-21 14:32:43,591 DEBUG AbstractSaveEventListener :: main :: saving [CatHistory#component[id,version]{id=1, version=1}]
2008-05-21 14:32:43,591 DEBUG StatefulPersistenceContext :: main :: setting proxy identifier: HistoryPK[id=1,version=1]
2008-05-21 14:32:43,591 DEBUG AbstractFlushingEventListener :: main :: flushing session
2008-05-21 14:32:43,591 DEBUG AbstractFlushingEventListener :: main :: processing flush-time cascades
2008-05-21 14:32:43,591 DEBUG AbstractFlushingEventListener :: main :: dirty checking collections
2008-05-21 14:32:43,591 DEBUG AbstractFlushingEventListener :: main :: Flushing entities and processing referenced collections
2008-05-21 14:32:43,591 DEBUG Collections :: main :: Collection found: [CatHistory.mice#component[id,version]{id=1, version=1}], was: [Cat.mice#1] (uninitialized)
2008-05-21 14:32:43,591 DEBUG Collections :: main :: Forcing collection initialization
2008-05-21 14:32:43,591 DEBUG DefaultInitializeCollectionEventListener :: main :: initializing collection [Cat.mice#1]
2008-05-21 14:32:43,591 DEBUG DefaultInitializeCollectionEventListener :: main :: checking second-level cache
2008-05-21 14:32:43,591 DEBUG DefaultInitializeCollectionEventListener :: main :: collection not cached
2008-05-21 14:32:43,591 DEBUG Loader :: main :: loading collection: [Cat.mice#1]
2008-05-21 14:32:43,591 DEBUG AbstractBatcher :: main :: about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
2008-05-21 14:32:43,591 DEBUG SQL :: main :: select mice0_.cat as cat0_, mice0_.rabid as rabid0_, mice0_.description as desc