[Hibernate-JIRA] Created: (HHH-2587) There is an attempt to set more parameters on a prepared statement than the latter can hold
by Zied Hamdi (JIRA)
There is an attempt to set more parameters on a prepared statement than the latter can hold
-------------------------------------------------------------------------------------------
Key: HHH-2587
URL: http://opensource.atlassian.com/projects/hibernate/browse/HHH-2587
Project: Hibernate3
Issue Type: Bug
Components: query-sql
Affects Versions: 3.2.3
Environment: JPA through hibernate
Reporter: Zied Hamdi
Priority: Blocker
Attachments: IntoCore.zip
You can directly import the zip content into netBeans 5.5 the just launch: the test is executed at the home page servlet call.
I have an index that doesn't exist : 11 (the total count of columns is 10) :
Hibernate: insert into BasicPersonArchiveEntry (endDate, entryPerformer_revision, entryPerformer_id, lastOccurence, note, startDate, source_revision, source_id, revision, id) values (?, ?, ?, ?, ?, ?, ?, ?, ?, ?)
could not bind value '0' to parameter: 11; Invalid argument: parameter index 11 is out of range.
SQL Error: -99999, SQLState: null
Invalid argument: parameter index 11 is out of range.
Could not synchronize database state with session
org.hibernate.exception.GenericJDBCException: could not insert: [com.homeservices.model.impl.BasicPersonArchiveEntry]
at org.hibernate.exception.SQLStateConverter.handledNonSpecificException(SQLStateConverter.java:103)
at org.hibernate.exception.SQLStateConverter.convert(SQLStateConverter.java:91)
at org.hibernate.exception.JDBCExceptionHelper.convert(JDBCExceptionHelper.java:43)
at org.hibernate.persister.entity.AbstractEntityPersister.insert(AbstractEntityPersister.java:2267)
at org.hibernate.persister.entity.AbstractEntityPersister.insert(AbstractEntityPersister.java:2660)
at org.hibernate.action.EntityInsertAction.execute(EntityInsertAction.java:52)
at org.hibernate.engine.ActionQueue.execute(ActionQueue.java:248)
at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:232)
at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:139)
at org.hibernate.event.def.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:298)
at org.hibernate.event.def.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:27)
at org.hibernate.impl.SessionImpl.flush(SessionImpl.java:1000)
at org.hibernate.impl.SessionImpl.managedFlush(SessionImpl.java:338)
at org.hibernate.ejb.AbstractEntityManagerImpl$1.beforeCompletion(AbstractEntityManagerImpl.java:516)
at com.sun.enterprise.distributedtx.J2EETransaction.commit(J2EETransaction.java:395)
at com.sun.enterprise.distributedtx.J2EETransactionManagerOpt.commit(J2EETransactionManagerOpt.java:357)
at com.sun.ejb.containers.BaseContainer.completeNewTx(BaseContainer.java:3653)
at com.sun.ejb.containers.BaseContainer.postInvokeTx(BaseContainer.java:3431)
at com.sun.ejb.containers.BaseContainer.postInvoke(BaseContainer.java:1247)
at com.sun.ejb.containers.EJBLocalObjectInvocationHandler.invoke(EJBLocalObjectInvocationHandler.java:192)
at com.sun.ejb.containers.EJBLocalObjectInvocationHandlerDelegate.invoke(EJBLocalObjectInvocationHandlerDelegate.java:118)
at $Proxy49.create(Unknown Source)
at tests.entities.TestArchiveServlet.processRequest(TestArchiveServlet.java:46)
at tests.entities.TestArchiveServlet.doGet(TestArchiveServlet.java:61)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:707)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:820)
at org.apache.catalina.core.ApplicationFilterChain.servletService(ApplicationFilterChain.java:397)
at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:278)
at org.apache.catalina.core.StandardPipeline.doInvoke(StandardPipeline.java:566)
at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:536)
at org.apache.catalina.core.StandardContextValve.invokeInternal(StandardContextValve.java:240)
at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:179)
at org.apache.catalina.core.StandardPipeline.doInvoke(StandardPipeline.java:566)
at com.sun.enterprise.web.WebPipeline.invoke(WebPipeline.java:73)
at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:182)
at org.apache.catalina.core.StandardPipeline.doInvoke(StandardPipeline.java:566)
at com.sun.enterprise.web.VirtualServerPipeline.invoke(VirtualServerPipeline.java:120)
at org.apache.catalina.core.ContainerBase.invoke(ContainerBase.java:939)
at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:137)
at org.apache.catalina.core.StandardPipeline.doInvoke(StandardPipeline.java:566)
at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:536)
at org.apache.catalina.core.ContainerBase.invoke(ContainerBase.java:939)
at org.apache.coyote.tomcat5.CoyoteAdapter.service(CoyoteAdapter.java:231)
at com.sun.enterprise.web.connector.grizzly.ProcessorTask.invokeAdapter(ProcessorTask.java:667)
at com.sun.enterprise.web.connector.grizzly.ProcessorTask.processNonBlocked(ProcessorTask.java:574)
at com.sun.enterprise.web.connector.grizzly.ProcessorTask.process(ProcessorTask.java:844)
at com.sun.enterprise.web.connector.grizzly.ReadTask.executeProcessorTask(ReadTask.java:287)
at com.sun.enterprise.web.connector.grizzly.ReadTask.doTask(ReadTask.java:212)
at com.sun.enterprise.web.connector.grizzly.TaskBase.run(TaskBase.java:252)
at com.sun.enterprise.web.connector.grizzly.WorkerThread.run(WorkerThread.java:75)
Caused by: org.apache.derby.client.am.SqlException: Invalid argument: parameter index 11 is out of range.
at org.apache.derby.client.am.PreparedStatement.checkForValidParameterIndex(Unknown Source)
at org.apache.derby.client.am.PreparedStatement.checkSetterPreconditions(Unknown Source)
at org.apache.derby.client.am.PreparedStatement.setLong(Unknown Source)
at org.hibernate.type.LongType.set(LongType.java:42)
at org.hibernate.type.NullableType.nullSafeSet(NullableType.java:136)
at org.hibernate.type.NullableType.nullSafeSet(NullableType.java:116)
at org.hibernate.type.ComponentType.nullSafeSet(ComponentType.java:284)
at org.hibernate.persister.entity.AbstractEntityPersister.dehydrate(AbstractEntityPersister.java:2008)
at org.hibernate.persister.entity.AbstractEntityPersister.insert(AbstractEntityPersister.java:2243)
... 46 more
EJB5018: An exception was thrown during an ejb invocation on [ArchivableFacadeStatelessBean]
javax.ejb.EJBException: Transaction aborted; nested exception is: javax.transaction.RollbackException: Transaction marked for rollback.
--
This message is automatically generated by JIRA.
-
If you think it was sent incorrectly contact one of the administrators: http://opensource.atlassian.com/projects/hibernate/secure/Administrators....
-
For more information on JIRA, see: http://www.atlassian.com/software/jira
15 years, 1 month
[Hibernate-JIRA] Created: (EJB-408) c3p0 not working with hibernate-entitymanager 3.4.0.GA
by Marcelo Romulo Fernandes (JIRA)
c3p0 not working with hibernate-entitymanager 3.4.0.GA
------------------------------------------------------
Key: EJB-408
URL: http://opensource.atlassian.com/projects/hibernate/browse/EJB-408
Project: Hibernate Entity Manager
Issue Type: Bug
Components: EntityManager
Affects Versions: 3.4.0.GA
Environment: windows xp sp2; java sun 1.6.0_10; tomcat 6.0.18; maven 2.0.9
Reporter: Marcelo Romulo Fernandes
Priority: Minor
I was using hibernate-entitymanager 3.2.6.GA and c3p0 well, but I cannot run c3p0 with hibernate-entitymanager 3.4.0.GA. c3p0 is never called!!!
Below, follows persistence.xml, maven dependencies working with hibernate-entitymanager 3.2.6.GA, maven dependencies not woking with hibernate-entitymanager 3.4.0.GA
persistence.xml:
<persistence version="1.0" xmlns="http://java.sun.com/xml/ns/persistence" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" xsi:schemaLocation="http://java.sun.com/xml/ns/persistence http://java.sun.com/xml/ns/persistence/persistence_1_0.xsd">
<persistence-unit name="SystemDDD" transaction-type="RESOURCE_LOCAL">
<provider>org.hibernate.ejb.HibernatePersistence</provider>
<properties>
<!-- Connection properties -->
<property name="hibernate.connection.username" value="DDD"/>
<property name="hibernate.connection.password" value="DDD"/>
<property name="hibernate.default_schema" value="DDD"/>
<property name="hibernate.connection.url" value="jdbc:oracle:thin:@//YYY:1521/ZZZ"/>
<property name="hibernate.connection.driver_class" value="oracle.jdbc.OracleDriver"/>
<property name="hibernate.dialect" value="org.hibernate.dialect.OracleDialect"/>
<!-- Connection pooling properties -->
<property name="hibernate.c3p0.min_size" value="1"/>
<property name="hibernate.c3p0.max_size" value="10"/>
<property name="hibernate.c3p0.timeout" value="5000"/>
<property name="hibernate.c3p0.max_statements" value="50"/>
<property name="hibernate.c3p0.idle_test_period" value="60000"/>
<!-- Cache properties -->
<property name="hibernate.cache.use_second_level_cache" value="true"/>
<property name="hibernate.cache.provider_class" value="org.hibernate.cache.EhCacheProvider"/>
<!-- Other properties -->
<property name="hibernate.show_sql" value="true"/>
<property name="hibernate.format_sql" value="true"/>
<property name="hibernate.archive.autodetection" value="class, hbm"/>
<property name="hibernate.hbm2ddl.auto" value="none"/>
</properties>
</persistence-unit>
</persistence>
maven dependencies working with hibernate-entitymanager 3.2.6.GA
<dependency>
<groupId>org.hibernate</groupId>
<artifactId>hibernate-entitymanager</artifactId>
<version>3.3.2.GA</version>
<type>jar</type>
<scope>compile</scope>
</dependency>
<dependency>
<groupId>c3p0</groupId>
<artifactId>c3p0</artifactId>
<version>0.9.1.2</version>
<type>jar</type>
<scope>compile</scope>
</dependency>
maven dependencies not woking with hibernate-entitymanager 3.4.0.GA
<dependency>
<groupId>org.hibernate</groupId>
<artifactId>hibernate-entitymanager</artifactId>
<version>3.4.0.GA</version>
<type>jar</type>
<scope>compile</scope>
</dependency>
<dependency>
<groupId>org.hibernate</groupId>
<artifactId>hibernate-ehcache</artifactId>
<version>3.3.0.SP1</version>
<type>jar</type>
<scope>runtime</scope>
</dependency>
<dependency>
<groupId>org.slf4j</groupId>
<artifactId>slf4j-log4j12</artifactId>
<version>1.5.2</version>
<type>jar</type>
<scope>runtime</scope>
</dependency>
<dependency>
<groupId>org.hibernate</groupId>
<artifactId>hibernate-c3p0</artifactId>
<version>3.3.0.SP1</version>
<type>jar</type>
<scope>runtime</scope>
</dependency>
What is wrong or missing?
--
This message is automatically generated by JIRA.
-
If you think it was sent incorrectly contact one of the administrators: http://opensource.atlassian.com/projects/hibernate/secure/Administrators....
-
For more information on JIRA, see: http://www.atlassian.com/software/jira
15 years, 1 month
[Hibernate-JIRA] Created: (HHH-2460) Multiple object creates on HQL select causes "unexpected token: ,"
by Steve Mayhew (JIRA)
Multiple object creates on HQL select causes "unexpected token: ,"
------------------------------------------------------------------
Key: HHH-2460
URL: http://opensource.atlassian.com/projects/hibernate/browse/HHH-2460
Project: Hibernate3
Type: Bug
Components: query-hql
Versions: 3.1.2
Environment: MySQL
Reporter: Steve Mayhew
When executing this query:
select new java.lang.String('test1'), new java.lang.String('test2')
from SomeMappedClass
You get a syntax error. It does not matter what is in the from clause, result is always the same.
[2007-03-01 16:51:29,349] [ERROR:org.hibernate.hql.PARSER] [] - line 1:37: unexpected token: ,
[2007-03-01 16:51:29,365] [DEBUG:org.hibernate.hql.ast.AST] [] - --- HQL AST ---
\-[QUERY] 'query'
org.hibernate.hql.ast.QuerySyntaxException: unexpected token: , near line 1, column 37 [select new java.lang.String('test1'), new java.lang.String('test2')
from SomeMappedClass
at org.hibernate.hql.ast.ErrorCounter.throwQueryException(ErrorCounter.java:59)
at org.hibernate.hql.ast.QueryTranslatorImpl.parse(QueryTranslatorImpl.java:244)
at org.hibernate.hql.ast.QueryTranslatorImpl.doCompile(QueryTranslatorImpl.java:155)
at org.hibernate.hql.ast.QueryTranslatorImpl.compile(QueryTranslatorImpl.java:109)
at org.hibernate.engine.query.HQLQueryPlan.<init>(HQLQueryPlan.java:75)
at org.hibernate.engine.query.HQLQueryPlan.<init>(HQLQueryPlan.java:54)
at org.hibernate.engine.query.QueryPlanCache.getHQLQueryPlan(QueryPlanCache.java:71)
at org.hibernate.impl.AbstractSessionImpl.getHQLQueryPlan(AbstractSessionImpl.java:134)
at org.hibernate.impl.AbstractSessionImpl.createQuery(AbstractSessionImpl.java:113)
at org.hibernate.impl.SessionImpl.createQuery(SessionImpl.java:1602)
at net.jvnet.dev.hqe.ThreadHQLQueryExecution.run(Unknown Source)
Caused by: line 1:37: unexpected token: ,
at org.hibernate.hql.antlr.HqlBaseParser.selectFrom(HqlBaseParser.java:1145)
at org.hibernate.hql.antlr.HqlBaseParser.queryRule(HqlBaseParser.java:702)
at org.hibernate.hql.antlr.HqlBaseParser.selectStatement(HqlBaseParser.java:296)
at org.hibernate.hql.antlr.HqlBaseParser.statement(HqlBaseParser.java:159)
at org.hibernate.hql.ast.QueryTranslatorImpl.parse(QueryTranslatorImpl.java:238)
... 9 more
--
This message is automatically generated by JIRA.
-
If you think it was sent incorrectly contact one of the administrators:
http://opensource.atlassian.com/projects/hibernate/secure/Administrators....
-
For more information on JIRA, see:
http://www.atlassian.com/software/jira
15 years, 2 months
[Hibernate-JIRA] Created: (HHH-3494) HQLQueryPlan gives back zero result for "getSingleResult()" although one result is available
by Christian Hofschroer (JIRA)
HQLQueryPlan gives back zero result for "getSingleResult()" although one result is available
--------------------------------------------------------------------------------------------
Key: HHH-3494
URL: http://opensource.atlassian.com/projects/hibernate/browse/HHH-3494
Project: Hibernate Core
Issue Type: Bug
Components: query-hql
Affects Versions: 3.3.1
Environment: 3.3.1.GA, hsqldb 1.8.0.7
Reporter: Christian Hofschroer
Attachments: patch.txt
I have run the following code snippets both and only the second one works, because there is a bug in HQLQueryPlan.
// This does not work correctly (query is javax.persistence.Query)
ExampleObject e = (ExampleObject) query.getSingleResult();
// Replacement with this code works
List l=query.getResultList() ;
assertEquals(1,l.size()) ;
ExampleObject e=(ExampleObject)l.get(0) ;
This problem occurs only in seldom cases when
1. Hibernate executes several sql queries and merges the result
and
2. There is a limit of results (the limit is "2" in version 3.3.1.GA, because only one result is expected anyway)
Attached is a patch for the class HQLQueryPlan. The line
if ( distinction.add( result ) ) {
has to be replaced with
if ( ! distinction.add( result ) ) {
In case the object was found it returns "true". With the current implementation the object is not added to "combinedResults" although it should be added.
It was not possible to reproduce the problem with the setup from "testsuite". If necessary I can provide a JUnit testcase.
--
This message is automatically generated by JIRA.
-
If you think it was sent incorrectly contact one of the administrators: http://opensource.atlassian.com/projects/hibernate/secure/Administrators....
-
For more information on JIRA, see: http://www.atlassian.com/software/jira
15 years, 2 months
[Hibernate-JIRA] Created: (HHH-3121) Using fetch="subselect" and second level cache causes NullPointerException
by Adam Brod (JIRA)
Using fetch="subselect" and second level cache causes NullPointerException
--------------------------------------------------------------------------
Key: HHH-3121
URL: http://opensource.atlassian.com/projects/hibernate/browse/HHH-3121
Project: Hibernate3
Issue Type: Bug
Components: caching (L2)
Affects Versions: 3.2.6
Environment: Oracle 10g
Reporter: Adam Brod
I've been tuning some of our mappings to use fetch="subselect" to reduce the number of DB queries. However, I have run into two cases where I get the exception below. In both cases, I was loading a list of Videos, which are mapped to a list of other objects. (In this example, Media is the superclass of Video.) I apologize that I can't upload a full working example, but I will include the relevant mapping info.
<class name="Media" table="media" lazy="false" discriminator-value="0">
<cache usage="nonstrict-read-write"/>
<id name="id" column="id" type="long">
<generator class="seqhilo"><param name="sequence">hibernate_hi_sequence</param><param name="max_lo">500</param></generator>
</id>
...
<list name="tags" lazy="true" table="media_tags" cascade="save-update" fetch="subselect">
<cache usage="nonstrict-read-write"/>
<key column="media_id"/>
<list-index column="idx"/>
<many-to-many column="tag_id" class="com.brightcove.catalog.Tag"/>
</list>
...
<subclass name="Video" lazy="false" discriminator-value="1">
...
</subclass>
</class>
<class name="Tag" table="tag">
...
</class>
The HQL being executed is just a simple "from Video v where v.publisher_id = :pubId".
The line of code where the exception is generated in Video.getDTO() is accessing the Tags list:
for (Tag tag : getTags()) {
tags.add(tag.getDTO());
}
I've debugged into the Hibernate source to see where the NPE comes from (CollectionLoadContext line 298).
if ( persister.isVersioned() ) {
versionComparator = persister.getOwnerEntityPersister().getVersionType().getComparator();
final Object collectionOwner = getLoadContext().getPersistenceContext().getCollectionOwner( lce.getKey(), persister );
version = getLoadContext().getPersistenceContext().getEntry( collectionOwner ).getVersion(); //NPE!
}
It seems that "collectionOwner" is null, so calling getEntry(collectionOwner) returns null. Calling getVersion() on a null entry is what throws the NPE.
java.lang.NullPointerException
at org.hibernate.engine.loading.CollectionLoadContext.addCollectionToCache(CollectionLoadContext.java:298)
at org.hibernate.engine.loading.CollectionLoadContext.endLoadingCollection(CollectionLoadContext.java:256)
at org.hibernate.engine.loading.CollectionLoadContext.endLoadingCollections(CollectionLoadContext.java:222)
at org.hibernate.engine.loading.CollectionLoadContext.endLoadingCollections(CollectionLoadContext.java:195)
at org.hibernate.loader.Loader.endCollectionLoad(Loader.java:877)
at org.hibernate.loader.Loader.initializeEntitiesAndCollections(Loader.java:865)
at org.hibernate.loader.Loader.doQuery(Loader.java:729)
at org.hibernate.loader.Loader.doQueryAndInitializeNonLazyCollections(Loader.java:236)
at org.hibernate.loader.Loader.loadCollectionSubselect(Loader.java:2066)
at org.hibernate.loader.collection.SubselectCollectionLoader.initialize(SubselectCollectionLoader.java:58)
at org.hibernate.persister.collection.AbstractCollectionPersister.initialize(AbstractCollectionPersister.java:565)
at org.hibernate.event.def.DefaultInitializeCollectionEventListener.onInitializeCollection(DefaultInitializeCollectionEventListener.java:60)
at org.hibernate.impl.SessionImpl.initializeCollection(SessionImpl.java:1716)
at org.hibernate.collection.AbstractPersistentCollection.initialize(AbstractPersistentCollection.java:344)
at org.hibernate.collection.AbstractPersistentCollection.read(AbstractPersistentCollection.java:86)
at org.hibernate.collection.AbstractPersistentCollection.readSize(AbstractPersistentCollection.java:109)
at org.hibernate.collection.PersistentList.size(PersistentList.java:91)
at com.brightcove.catalog.EconomicEntity.populateDTO(EconomicEntity.java:460)
at com.brightcove.catalog.Media.populateDTO(Media.java:192)
at com.brightcove.catalog.Video.populateDTO(Video.java:854)
at com.brightcove.catalog.Video.getDTO(Video.java:783)
at com.brightcove.catalog.Video.getDTO(Video.java:756)
--
This message is automatically generated by JIRA.
-
If you think it was sent incorrectly contact one of the administrators: http://opensource.atlassian.com/projects/hibernate/secure/Administrators....
-
For more information on JIRA, see: http://www.atlassian.com/software/jira
15 years, 2 months
[Hibernate-JIRA] Created: (ANN-687) orm.xml - cleanup respecting column names
by darren hartford (JIRA)
orm.xml - cleanup respecting column names
-----------------------------------------
Key: ANN-687
URL: http://opensource.atlassian.com/projects/hibernate/browse/ANN-687
Project: Hibernate Annotations
Issue Type: Bug
Components: binder
Affects Versions: 3.3.0.ga
Environment: mysql 5, MS SQL 2000, Win2000, hibernate 3.2.4
Reporter: darren hartford
couple of issues with orm.xml mapping file that is not fully implemented and needs cleanup.
many-to-many table mapping not respecting column names.
http://forum.hibernate.org/viewtopic.php?t=982330
id-class not respecting column names (end of an old issue, repeated with different scenario).
http://opensource.atlassian.com/projects/hibernate/browse/ANN-361
<id-class class="MyTestId"/>
<attributes>
<id name="compoundOne">
<column name="COMPOUND_ONE"/>
</id>
<id name="compoundTwo">
<column name="COMPOUND_TWO"/>
</id>
...
WARNING: Preparing the statement failed: Invalid column name 'compoundOne'.
WARNING: Preparing the statement failed: Invalid column name 'compoundTwo'.
==========
Use case and urgency of issue related to external technology integration.
-DTO should not require hibernate-annotations to be used in client-code, but is required when using annotations. orm.xml approach removes this limitation.
-GWT 1.4 does not work with java 1.5/annotated DTO. Although everyone keeps pushing it off saying 'GWT 1.5 is on the way', it is not and solutions that should have been working to work around that limitation need to be working correctly.
--
This message is automatically generated by JIRA.
-
If you think it was sent incorrectly contact one of the administrators: http://opensource.atlassian.com/projects/hibernate/secure/Administrators....
-
For more information on JIRA, see: http://www.atlassian.com/software/jira
15 years, 2 months
[Hibernate-JIRA] Created: (HHH-5056) Criteria API with ProjectionList and Unique result
by Ahmed Ali Elsayed Ali Soliman (JIRA)
Criteria API with ProjectionList and Unique result
--------------------------------------------------
Key: HHH-5056
URL: http://opensource.atlassian.com/projects/hibernate/browse/HHH-5056
Project: Hibernate Core
Issue Type: Bug
Components: query-criteria
Affects Versions: 3.5.0-CR-2
Environment: Hibernate 3.3.2, Oracel 11g
Reporter: Ahmed Ali Elsayed Ali Soliman
Priority: Critical
when you make a select statement with Criteria API & use ProjectionList to retrieve some columns then use the unique result
make at least 2 projection list (2 columns or more)
ProjectionList projectionList = Projections.projectionList() .add(Projections.property("ColumnA")) .add(Projections.property("ColumnB"));
criteria.setResultTransformer(CriteriaSpecification.DISTINCT_ROOT_ENTITY);
the result must be retrieved in 2 dimensional array of Object(Object[][])
but the result are one dimensional array with one column only.
Note:- when you remove the unique result it works fine but when you add it, it make this behavior.
--
This message is automatically generated by JIRA.
-
If you think it was sent incorrectly contact one of the administrators: http://opensource.atlassian.com/projects/hibernate/secure/Administrators....
-
For more information on JIRA, see: http://www.atlassian.com/software/jira
15 years, 2 months
[Hibernate-JIRA] Created: (ANN-472) @UniqueConstraint declaration is not friendly towards inheritance or reflection
by Ted Bergeron (JIRA)
@UniqueConstraint declaration is not friendly towards inheritance or reflection
-------------------------------------------------------------------------------
Key: ANN-472
URL: http://opensource.atlassian.com/projects/hibernate/browse/ANN-472
Project: Hibernate Annotations
Type: Improvement
Versions: 3.2.0.ga
Environment: Hibernate 3.2 GA
Reporter: Ted Bergeron
The current way to define a composite unique constraint is limiting.
@Table(name="tbl_sky",
uniqueConstraints = {@UniqueConstraint(columnNames={"month", "day"})}
)
Suppose I have an abstract base class called A that gives me Id and Name, subclassed by abstract class B that gives me Customer. Then I have many concrete classes that subclass B. For all of these, I'd want the combination of Name and Customer to be unique. As I do not use @Table with abstract base classes, I currently have to repeat: uniqueConstraints = {@UniqueConstraint(columnNames={"name", "customer_id"})} on all concrete classes.
If we had an alternate way to define these constraints at the property level (as XDoclet did with hibernate 2), I could define this in the base classes and inherit the constraint declaration.
The other need is that I would like to use reflection to scan the properties and apply proper validations in the view layer. With @Column(unique = true) this is easy to do. The view layer makes an AJAX call and all is well. For a composite constraint, it does not work well currently.
--
This message is automatically generated by JIRA.
-
If you think it was sent incorrectly contact one of the administrators:
http://opensource.atlassian.com/projects/hibernate/secure/Administrators....
-
For more information on JIRA, see:
http://www.atlassian.com/software/jira
15 years, 2 months
[Hibernate-JIRA] Created: (HHH-4939) Bidirectional OneToOne mapping with FK and composite PK sharing a column throws MappingException
by Chris Wilson (JIRA)
Bidirectional OneToOne mapping with FK and composite PK sharing a column throws MappingException
------------------------------------------------------------------------------------------------
Key: HHH-4939
URL: http://opensource.atlassian.com/projects/hibernate/browse/HHH-4939
Project: Hibernate Core
Issue Type: Bug
Components: core
Affects Versions: 3.3.2
Reporter: Chris Wilson
Attachments: HibernateAnnotationMappingOneToOneTest.java
A bidirectional one-to-one mapping, where the owning side's column is part of a composite primary key, fails to configure, possibly because OneToOneType#getColumnSpan returns zero instead of the actual number of columns used by the join.
When the foreign key column used is not also part of the primary key, or the composite primary key contains only a single column, then the mapping doesn't fail.
{code}
org.hibernate.MappingException: broken column mapping for: journeyComment.id of: org.wfp.rita.test.hibernate.HibernateAnnotationMappingOneToOneTest$Journey
at org.hibernate.persister.entity.AbstractPropertyMapping.initPropertyPaths(AbstractPropertyMapping.java:143)
at org.hibernate.persister.entity.AbstractPropertyMapping.initIdentifierPropertyPaths(AbstractPropertyMapping.java:206)
at org.hibernate.persister.entity.AbstractPropertyMapping.initPropertyPaths(AbstractPropertyMapping.java:181)
at org.hibernate.persister.entity.AbstractEntityPersister.initOrdinaryPropertyPaths(AbstractEntityPersister.java:1725)
at org.hibernate.persister.entity.AbstractEntityPersister.initPropertyPaths(AbstractEntityPersister.java:1755)
at org.hibernate.persister.entity.AbstractEntityPersister.postConstruct(AbstractEntityPersister.java:2932)
at org.hibernate.persister.entity.SingleTableEntityPersister.<init>(SingleTableEntityPersister.java:431)
at org.hibernate.persister.PersisterFactory.createClassPersister(PersisterFactory.java:84)
at org.hibernate.impl.SessionFactoryImpl.<init>(SessionFactoryImpl.java:267)
at org.hibernate.cfg.Configuration.buildSessionFactory(Configuration.java:1341)
at org.hibernate.cfg.AnnotationConfiguration.buildSessionFactory(AnnotationConfiguration.java:867)
at org.wfp.rita.test.base.HibernateTestBase.buildSessionFactory(HibernateTestBase.java:93)
at org.wfp.rita.test.base.HibernateTestBase.setUp(HibernateTestBase.java:106)
at junit.framework.TestCase.runBare(TestCase.java:128)
at junit.framework.TestResult$1.protect(TestResult.java:106)
at junit.framework.TestResult.runProtected(TestResult.java:124)
at junit.framework.TestResult.run(TestResult.java:109)
at junit.framework.TestCase.run(TestCase.java:120)
at junit.framework.TestSuite.runTest(TestSuite.java:230)
at junit.framework.TestSuite.run(TestSuite.java:225)
at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.runTests(RemoteTestRunner.java:478)
at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.run(RemoteTestRunner.java:344)
at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.main(RemoteTestRunner.java:196)
{code}
Test case attached. Change HibernateTestBase to org.hibernate.test.annotations.TestCase to run under Hibernate.
--
This message is automatically generated by JIRA.
-
If you think it was sent incorrectly contact one of the administrators: http://opensource.atlassian.com/projects/hibernate/secure/Administrators....
-
For more information on JIRA, see: http://www.atlassian.com/software/jira
15 years, 2 months
[Hibernate-JIRA] Created: (HHH-2692) Insert Into Select command doesn't allow named parameter as select output (insert input)
by John Aylward (JIRA)
Insert Into Select command doesn't allow named parameter as select output (insert input)
----------------------------------------------------------------------------------------
Key: HHH-2692
URL: http://opensource.atlassian.com/projects/hibernate/browse/HHH-2692
Project: Hibernate3
Issue Type: Bug
Components: query-hql
Affects Versions: 3.2.4.sp1
Environment: Hibernate 3.2.4.sp1 with Annotations 3.3.0 And Validator 3.0.0
MySQL 5.0.42
Reporter: John Aylward
receive exception:
org.hibernate.QueryException: number of select types did not match those for insert [INSERT INTO ProviderInvoiceLineItem (amount,billingAccount,circuit,description,invoice,type) SELECT pili.amount, pili.billingAccount, pili.circuit, pili.description, :newInvoice, pili.type FROM com.cicat.bedrock.billing.model.ProviderInvoiceLineItem pili WHERE pili.invoice = :oldInvoice]
Idea is to copy all line items from one invoice to another. In other words, only difference between data should be the invoice. easiest way to do this is with "insert into" command and passing parameter of changed value.
* Trying to cast named parameter (:newInvoice) caused parsing error
* Trying to replace invoice with invoice_id and repacing :newInvoice with actual invoice id resulted in a "property 'invoice_id' not found" exception
Should be able to set a value through a named parameter
--
This message is automatically generated by JIRA.
-
If you think it was sent incorrectly contact one of the administrators: http://opensource.atlassian.com/projects/hibernate/secure/Administrators....
-
For more information on JIRA, see: http://www.atlassian.com/software/jira
15 years, 2 months
[Hibernate-JIRA] Created: (HHH-2391) ManyToMany+FetchMode.SUBSELECT+2nd level cache= NPE
by Mike Youngstrom (JIRA)
ManyToMany+FetchMode.SUBSELECT+2nd level cache= NPE
---------------------------------------------------
Key: HHH-2391
URL: http://opensource.atlassian.com/projects/hibernate/browse/HHH-2391
Project: Hibernate3
Type: Bug
Components: core
Versions: 3.2.2
Reporter: Mike Youngstrom
For more context see the forum post here: http://forum.hibernate.org/viewtopic.php?t=968643
I have a model animal with s many-to-many with country. I do a @Fetch(FetchMode.SUBSELECT) on animal.countries.
When I query for an animal I get a NPE. If I remove the @Fetch(FetchMode.SUBSELECT) from animal.countries then everything works fine. If I remove @Cache from animal.countries then everything works fine.
I've included Animal and the inverse (Country) I've also included a trace log of the error happening from a query of Animal.
--------------Animal.java-----------------
public class Animal implements Serializable {
public static final String QUERY_GET_ALL_ANIMALS_AS_SELECT_ITEMS = "getAllAnimalsAsSelectItems";
@Id @GeneratedValue
private Long id;
@Temporal(TemporalType.TIMESTAMP)
@Column(name="CREATED", nullable = false, updatable = false)
private Date created = new Date();
@Column(unique=true, nullable=false)
private String name;
@Enumerated(EnumType.STRING)
private Gender gender;
@Column(length=4000)
private String description;
private String imageUrl;
@Column(nullable=false)
private double price;
private Date dateOfBirth;
@ManyToOne(fetch=FetchType.LAZY)
private Classification classification;
@ManyToMany(fetch=FetchType.EAGER)
@JoinTable(name="ANIMAL_COUNTRY",
joinColumns=@JoinColumn(name="ANIMAL_ID"),
inverseJoinColumns=@JoinColumn(name="COUNTRY_ID"))
@Cache(usage=CacheConcurrencyStrategy.TRANSACTIONAL)
@BatchSize(size=10)
@OrderBy("name")
@Fetch(FetchMode.SUBSELECT)
private Set<Country> countries;
@SuppressWarnings("unused")
@Version
private Long version = 1L;
}
----------------Country.java------------------
public class Country implements Serializable {
public static final String QUERY_ALL_COUNTRY_IDS_AS_SELECT_ITEMS = "allCountryIdsAsSelectItems";
public static final String QUERY_ALL_COUNTRIES_AS_SELECT_ITEMS = "allCountriesAsSelectItems";
@Id @GeneratedValue @Column(updatable=false)
private Long id;
@Column(unique=true, nullable=false)
public String name;
@Cache(usage=CacheConcurrencyStrategy.TRANSACTIONAL)
@ManyToMany(mappedBy="countries", fetch=FetchType.EAGER)
@Fetch(FetchMode.SUBSELECT)
@BatchSize(size=20)
public Set<Animal> animals;
}
-------------------LOG----------------------------
10:44:18,453 DEBUG SQL:
/* select
a
from
Animal a
where
upper(a.name) like upper(?1)
order by
upper(name) ASC */ select
*
from
( select
animal0_.id as id1_,
animal0_.CREATED as CREATED1_,
animal0_.name as name1_,
animal0_.gender as gender1_,
animal0_.description as descript5_1_,
animal0_.imageUrl as imageUrl1_,
animal0_.price as price1_,
animal0_.dateOfBirth as dateOfBi8_1_,
animal0_.classification_id as classif10_1_,
animal0_.version as version1_
from
Animal animal0_
where
upper(animal0_.name) like upper(?)
order by
upper(animal0_.name) ASC )
where
rownum <= ?
Hibernate:
/* select
a
from
Animal a
where
upper(a.name) like upper(?1)
order by
upper(name) ASC */ select
*
from
( select
animal0_.id as id1_,
animal0_.CREATED as CREATED1_,
animal0_.name as name1_,
animal0_.gender as gender1_,
animal0_.description as descript5_1_,
animal0_.imageUrl as imageUrl1_,
animal0_.price as price1_,
animal0_.dateOfBirth as dateOfBi8_1_,
animal0_.classification_id as classif10_1_,
animal0_.version as version1_
from
Animal animal0_
where
upper(animal0_.name) like upper(?)
order by
upper(animal0_.name) ASC )
where
rownum <= ?
10:44:18,453 DEBUG AbstractBatcher: preparing statement
10:44:18,453 DEBUG StringType: binding '%' to parameter: 1
10:44:18,453 DEBUG AbstractBatcher: about to open ResultSet (open ResultSets: 0, globally: 0)
10:44:18,453 DEBUG Loader: processing result set
10:44:18,453 DEBUG Loader: result set row: 0
10:44:18,453 DEBUG LongType: returning '505' as column: id1_
10:44:18,453 DEBUG Loader: result row: EntityKey[org.lds.stack.petstore.model.Animal#505]
10:44:18,453 DEBUG Loader: Initializing object from ResultSet: [org.lds.stack.petstore.model.Animal#505]
10:44:18,453 DEBUG AbstractEntityPersister: Hydrating entity: [org.lds.stack.petstore.model.Animal#505]
10:44:18,453 DEBUG TimestampType: returning '2007-01-26 14:12:19' as column: CREATED1_
10:44:18,453 DEBUG StringType: returning 'aaaaa' as column: name1_
10:44:18,453 DEBUG EnumType: Returning 'MALE' as column gender1_
10:44:18,453 DEBUG StringType: returning 'aaaaafasd
asdf
asdfs
adgadf
gdfagdfagfasdgasdfgadfgdfvgd
faxdc
fasdfa
sdfsdfuyasdgfjsdh sjfhsdjf has sd fjadb ddf
fjasdfhs djfas
ad
fasd fajksdhf'asdkfja
f asdfjkasdfhasdf
asdfhasjdfa
sdfasdfha'sdfha'sdfhasd'fa
sfasd
f
asdfasdkf;askfjasd fasd
fafjak;j
fagiajf
asdfgifgjdfklgja;fweai[tfjadfk iafjja'dfjasdifhasdf
afkasdjfiadadi ;asdifh;sfare ' as column: descript5_1_
10:44:18,453 DEBUG StringType: returning null as column: imageUrl1_
10:44:18,453 DEBUG DoubleType: returning '2.0' as column: price1_
10:44:18,453 DEBUG TimestampType: returning '2007-01-11 00:00:00' as column: dateOfBi8_1_
10:44:18,453 DEBUG LongType: returning '1' as column: classif10_1_
10:44:18,453 DEBUG LongType: returning '2' as column: version1_
10:44:18,453 DEBUG TwoPhaseLoad: Version: 2
10:44:18,453 DEBUG Loader: result set row: 1
10:44:18,453 DEBUG LongType: returning '19' as column: id1_
10:44:18,453 DEBUG Loader: result row: EntityKey[org.lds.stack.petstore.model.Animal#19]
10:44:18,453 DEBUG Loader: Initializing object from ResultSet: [org.lds.stack.petstore.model.Animal#19]
10:44:18,453 DEBUG AbstractEntityPersister: Hydrating entity: [org.lds.stack.petstore.model.Animal#19]
10:44:18,453 DEBUG TimestampType: returning '2007-01-17 13:43:45' as column: CREATED1_
10:44:18,453 DEBUG StringType: returning 'Alligator' as column: name1_
10:44:18,453 DEBUG EnumType: Returning 'FEMALE' as column gender1_
10:44:18,453 DEBUG StringType: returning 'The American Alligator is the biggest reptile in North America. Get this critter to raise your own pair of boots. She loves basking in the sun and eating neighborhood dogs. Especially likes cats.' as column: descript5_1_
10:44:18,453 DEBUG StringType: returning '/images/animals/alligator.jpg' as column: imageUrl1_
10:44:18,453 DEBUG DoubleType: returning '100.0' as column: price1_
10:44:18,453 DEBUG TimestampType: returning '2006-04-21 00:00:00' as column: dateOfBi8_1_
10:44:18,453 DEBUG LongType: returning '3' as column: classif10_1_
10:44:18,453 DEBUG LongType: returning '15' as column: version1_
10:44:18,453 DEBUG TwoPhaseLoad: Version: 15
10:44:18,453 DEBUG Loader: result set row: 2
10:44:18,453 DEBUG LongType: returning '15' as column: id1_
10:44:18,453 DEBUG Loader: result row: EntityKey[org.lds.stack.petstore.model.Animal#15]
10:44:18,453 DEBUG Loader: Initializing object from ResultSet: [org.lds.stack.petstore.model.Animal#15]
10:44:18,453 DEBUG AbstractEntityPersister: Hydrating entity: [org.lds.stack.petstore.model.Animal#15]
10:44:18,453 DEBUG TimestampType: returning '2007-01-17 13:43:45' as column: CREATED1_
10:44:18,453 DEBUG StringType: returning 'Amazon Parrot' as column: name1_
10:44:18,453 DEBUG EnumType: Returning 'MALE' as column gender1_
10:44:18,453 DEBUG StringType: returning 'Great companion for up to 75 years' as column: descript5_1_
10:44:18,453 DEBUG StringType: returning '/images/animals/bird4.gif' as column: imageUrl1_
10:44:18,453 DEBUG DoubleType: returning '100.0' as column: price1_
10:44:18,453 DEBUG TimestampType: returning '2006-04-21 06:05:05' as column: dateOfBi8_1_
10:44:18,453 DEBUG LongType: returning '5' as column: classif10_1_
10:44:18,453 DEBUG LongType: returning '1' as column: version1_
10:44:18,453 DEBUG TwoPhaseLoad: Version: 1
10:44:18,453 DEBUG Loader: result set row: 3
10:44:18,453 DEBUG LongType: returning '25' as column: id1_
10:44:18,453 DEBUG Loader: result row: EntityKey[org.lds.stack.petstore.model.Animal#25]
10:44:18,453 DEBUG Loader: Initializing object from ResultSet: [org.lds.stack.petstore.model.Animal#25]
10:44:18,453 DEBUG AbstractEntityPersister: Hydrating entity: [org.lds.stack.petstore.model.Animal#25]
10:44:18,453 DEBUG TimestampType: returning '2007-01-17 13:43:46' as column: CREATED1_
10:44:18,453 DEBUG StringType: returning 'American Bullfrog' as column: name1_
10:44:18,453 DEBUG EnumType: Returning 'MALE' as column gender1_
10:44:18,453 DEBUG StringType: returning 'Perhaps the most recognized amphibian on the continent, the Bullfrog is, among other things, an awesome predator. In its watery home it will eat other frogs and amphibians, fishes, small snakes, and even small songbirds and baby ducks -- if it has the chance.' as column: descript5_1_
10:44:18,453 DEBUG StringType: returning '/images/animals/bullfrog.jpg' as column: imageUrl1_
10:44:18,453 DEBUG DoubleType: returning '100.0' as column: price1_
10:44:18,468 DEBUG TimestampType: returning '2006-04-21 06:05:05' as column: dateOfBi8_1_
10:44:18,468 DEBUG LongType: returning '8' as column: classif10_1_
10:44:18,468 DEBUG LongType: returning '1' as column: version1_
10:44:18,468 DEBUG TwoPhaseLoad: Version: 1
10:44:18,468 DEBUG Loader: result set row: 4
10:44:18,468 DEBUG LongType: returning '30' as column: id1_
10:44:18,468 DEBUG Loader: result row: EntityKey[org.lds.stack.petstore.model.Animal#30]
10:44:18,468 DEBUG Loader: Initializing object from ResultSet: [org.lds.stack.petstore.model.Animal#30]
10:44:18,468 DEBUG AbstractEntityPersister: Hydrating entity: [org.lds.stack.petstore.model.Animal#30]
10:44:18,468 DEBUG TimestampType: returning '2007-01-17 13:43:46' as column: CREATED1_
10:44:18,468 DEBUG StringType: returning 'American Crocodile' as column: name1_
10:44:18,468 DEBUG EnumType: Returning 'MALE' as column gender1_
10:44:18,468 DEBUG StringType: returning 'Usually not more than 15 feet long in the U.S., this species may have reached 23 feet in South America. The adults diet includes crabs, fish (especially mullet), raccoons, waterbirds, and small neighborhood animals.' as column: descript5_1_
10:44:18,468 DEBUG StringType: returning '/images/animals/crocodile.jpg' as column: imageUrl1_
10:44:18,468 DEBUG DoubleType: returning '100.0' as column: price1_
10:44:18,468 DEBUG TimestampType: returning '2006-04-21 06:05:05' as column: dateOfBi8_1_
10:44:18,468 DEBUG LongType: returning '3' as column: classif10_1_
10:44:18,468 DEBUG LongType: returning '1' as column: version1_
10:44:18,468 DEBUG TwoPhaseLoad: Version: 1
10:44:18,468 DEBUG Loader: done processing result set (5 rows)
10:44:18,468 DEBUG AbstractBatcher: about to close ResultSet (open ResultSets: 1, globally: 1)
10:44:18,468 DEBUG AbstractBatcher: about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
10:44:18,468 DEBUG AbstractBatcher: closing statement
10:44:18,468 DEBUG ConnectionManager: aggressively releasing JDBC connection
10:44:18,468 DEBUG ConnectionManager: releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
10:44:18,468 DEBUG Loader: total objects hydrated: 5
10:44:18,468 DEBUG TwoPhaseLoad: resolving associations for [org.lds.stack.petstore.model.Animal#505]
10:44:18,468 DEBUG DefaultLoadEventListener: loading entity: [org.lds.stack.petstore.model.Classification#1]
10:44:18,468 DEBUG DefaultLoadEventListener: creating new proxy for entity
10:44:18,468 DEBUG CollectionLoadContext: creating collection wrapper:[org.lds.stack.petstore.model.Animal.countries#505]
10:44:18,468 DEBUG TwoPhaseLoad: adding entity to second-level cache: [org.lds.stack.petstore.model.Animal#505]
10:44:18,468 DEBUG TransactionalCache: item already cached: org.lds.stack.petstore.model.Animal#505
10:44:18,468 DEBUG TwoPhaseLoad: done materializing entity [org.lds.stack.petstore.model.Animal#505]
10:44:18,468 DEBUG TwoPhaseLoad: resolving associations for [org.lds.stack.petstore.model.Animal#19]
10:44:18,468 DEBUG DefaultLoadEventListener: loading entity: [org.lds.stack.petstore.model.Classification#3]
10:44:18,468 DEBUG DefaultLoadEventListener: creating new proxy for entity
10:44:18,468 DEBUG CollectionLoadContext: creating collection wrapper:[org.lds.stack.petstore.model.Animal.countries#19]
10:44:18,468 DEBUG TwoPhaseLoad: adding entity to second-level cache: [org.lds.stack.petstore.model.Animal#19]
10:44:18,468 DEBUG TransactionalCache: item already cached: org.lds.stack.petstore.model.Animal#19
10:44:18,468 DEBUG TwoPhaseLoad: done materializing entity [org.lds.stack.petstore.model.Animal#19]
10:44:18,468 DEBUG TwoPhaseLoad: resolving associations for [org.lds.stack.petstore.model.Animal#15]
10:44:18,468 DEBUG DefaultLoadEventListener: loading entity: [org.lds.stack.petstore.model.Classification#5]
10:44:18,468 DEBUG DefaultLoadEventListener: creating new proxy for entity
10:44:18,468 DEBUG CollectionLoadContext: creating collection wrapper:[org.lds.stack.petstore.model.Animal.countries#15]
10:44:18,468 DEBUG TwoPhaseLoad: adding entity to second-level cache: [org.lds.stack.petstore.model.Animal#15]
10:44:18,468 DEBUG TransactionalCache: item already cached: org.lds.stack.petstore.model.Animal#15
10:44:18,468 DEBUG TwoPhaseLoad: done materializing entity [org.lds.stack.petstore.model.Animal#15]
10:44:18,468 DEBUG TwoPhaseLoad: resolving associations for [org.lds.stack.petstore.model.Animal#25]
10:44:18,468 DEBUG DefaultLoadEventListener: loading entity: [org.lds.stack.petstore.model.Classification#8]
10:44:18,468 DEBUG DefaultLoadEventListener: creating new proxy for entity
10:44:18,468 DEBUG CollectionLoadContext: creating collection wrapper:[org.lds.stack.petstore.model.Animal.countries#25]
10:44:18,468 DEBUG TwoPhaseLoad: adding entity to second-level cache: [org.lds.stack.petstore.model.Animal#25]
10:44:18,468 DEBUG TransactionalCache: item already cached: org.lds.stack.petstore.model.Animal#25
10:44:18,468 DEBUG TwoPhaseLoad: done materializing entity [org.lds.stack.petstore.model.Animal#25]
10:44:18,468 DEBUG TwoPhaseLoad: resolving associations for [org.lds.stack.petstore.model.Animal#30]
10:44:18,468 DEBUG DefaultLoadEventListener: loading entity: [org.lds.stack.petstore.model.Classification#3]
10:44:18,468 DEBUG DefaultLoadEventListener: entity proxy found in session cache
10:44:18,468 DEBUG CollectionLoadContext: creating collection wrapper:[org.lds.stack.petstore.model.Animal.countries#30]
10:44:18,468 DEBUG TwoPhaseLoad: adding entity to second-level cache: [org.lds.stack.petstore.model.Animal#30]
10:44:18,468 DEBUG TransactionalCache: item already cached: org.lds.stack.petstore.model.Animal#30
10:44:18,468 DEBUG TwoPhaseLoad: done materializing entity [org.lds.stack.petstore.model.Animal#30]
10:44:18,468 DEBUG StatefulPersistenceContext: initializing non-lazy collections
10:44:18,468 DEBUG DefaultInitializeCollectionEventListener: initializing collection [org.lds.stack.petstore.model.Animal.countries#30]
10:44:18,468 DEBUG DefaultInitializeCollectionEventListener: checking second-level cache
10:44:18,468 DEBUG TransactionalCache: cache lookup: org.lds.stack.petstore.model.Animal.countries#30
10:44:18,468 DEBUG TransactionalCache: cache miss
10:44:18,468 DEBUG DefaultInitializeCollectionEventListener: collection not cached
10:44:18,468 DEBUG BasicCollectionLoader: Static select for collection org.lds.stack.petstore.model.Animal.countries: /* load collection org.lds.stack.petstore.model.Animal.countries */ select countries0_.ANIMAL_ID as ANIMAL1_1_, countries0_.COUNTRY_ID as COUNTRY2_1_, country1_.id as id3_0_, country1_.name as name3_0_ from ANIMAL_COUNTRY countries0_ left outer join Country country1_ on countries0_.COUNTRY_ID=country1_.id where countries0_.ANIMAL_ID in (select animal0_.id from Animal animal0_ where upper(animal0_.name) like upper(?) ) order by country1_.name asc
10:44:18,468 DEBUG AbstractBatcher: about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
10:44:18,468 DEBUG ConnectionManager: opening JDBC connection
10:44:18,468 DEBUG SQL:
/* load collection org.lds.stack.petstore.model.Animal.countries */ select
countries0_.ANIMAL_ID as ANIMAL1_1_,
countries0_.COUNTRY_ID as COUNTRY2_1_,
country1_.id as id3_0_,
country1_.name as name3_0_
from
ANIMAL_COUNTRY countries0_
left outer join
Country country1_
on countries0_.COUNTRY_ID=country1_.id
where
countries0_.ANIMAL_ID in (
select
animal0_.id
from
Animal animal0_
where
upper(animal0_.name) like upper(?)
)
order by
country1_.name asc
Hibernate:
/* load collection org.lds.stack.petstore.model.Animal.countries */ select
countries0_.ANIMAL_ID as ANIMAL1_1_,
countries0_.COUNTRY_ID as COUNTRY2_1_,
country1_.id as id3_0_,
country1_.name as name3_0_
from
ANIMAL_COUNTRY countries0_
left outer join
Country country1_
on countries0_.COUNTRY_ID=country1_.id
where
countries0_.ANIMAL_ID in (
select
animal0_.id
from
Animal animal0_
where
upper(animal0_.name) like upper(?)
)
order by
country1_.name asc
10:44:18,468 DEBUG AbstractBatcher: preparing statement
10:44:18,468 DEBUG Loader: bindNamedParameters() % -> 1 [1]
10:44:18,468 DEBUG StringType: binding '%' to parameter: 1
10:44:18,484 DEBUG AbstractBatcher: about to open ResultSet (open ResultSets: 0, globally: 0)
10:44:18,484 DEBUG Loader: result set contains (possibly empty) collection: [org.lds.stack.petstore.model.Animal.countries#25]
10:44:18,484 DEBUG CollectionLoadContext: uninitialized collection: initializing
10:44:18,484 DEBUG Loader: result set contains (possibly empty) collection: [org.lds.stack.petstore.model.Animal.countries#505]
10:44:18,484 DEBUG CollectionLoadContext: uninitialized collection: initializing
10:44:18,484 DEBUG Loader: result set contains (possibly empty) collection: [org.lds.stack.petstore.model.Animal.countries#15]
10:44:18,484 DEBUG CollectionLoadContext: uninitialized collection: initializing
10:44:18,484 DEBUG Loader: result set contains (possibly empty) collection: [org.lds.stack.petstore.model.Animal.countries#30]
10:44:18,484 DEBUG CollectionLoadContext: uninitialized collection: initializing
10:44:18,484 DEBUG Loader: result set contains (possibly empty) collection: [org.lds.stack.petstore.model.Animal.countries#19]
10:44:18,484 DEBUG CollectionLoadContext: uninitialized collection: initializing
10:44:18,484 DEBUG Loader: processing result set
10:44:18,484 DEBUG Loader: result set row: 0
10:44:18,484 DEBUG LongType: returning '1' as column: id3_0_
10:44:18,484 DEBUG Loader: result row: EntityKey[org.lds.stack.petstore.model.Country#1]
10:44:18,484 DEBUG Loader: Initializing object from ResultSet: [org.lds.stack.petstore.model.Country#1]
10:44:18,484 DEBUG AbstractEntityPersister: Hydrating entity: [org.lds.stack.petstore.model.Country#1]
10:44:18,484 DEBUG StringType: returning 'Afghanistan' as column: name3_0_
10:44:18,484 DEBUG LongType: returning '19' as column: ANIMAL1_1_
10:44:18,484 DEBUG Loader: found row of collection: [org.lds.stack.petstore.model.Animal.countries#19]
10:44:18,484 DEBUG CollectionLoadContext: reading row
10:44:18,484 DEBUG LongType: returning '1' as column: COUNTRY2_1_
10:44:18,484 DEBUG DefaultLoadEventListener: loading entity: [org.lds.stack.petstore.model.Country#1]
10:44:18,484 DEBUG DefaultLoadEventListener: attempting to resolve: [org.lds.stack.petstore.model.Country#1]
10:44:18,484 DEBUG DefaultLoadEventListener: resolved object in session cache: [org.lds.stack.petstore.model.Country#1]
10:44:18,484 DEBUG Loader: result set row: 1
10:44:18,484 DEBUG LongType: returning '1' as column: id3_0_
10:44:18,484 DEBUG Loader: result row: EntityKey[org.lds.stack.petstore.model.Country#1]
10:44:18,484 DEBUG LongType: returning '23' as column: ANIMAL1_1_
10:44:18,484 DEBUG Loader: found row of collection: [org.lds.stack.petstore.model.Animal.countries#23]
10:44:18,484 DEBUG CollectionLoadContext: new collection: instantiating
10:44:18,484 DEBUG LongType: returning '1' as column: COUNTRY2_1_
10:44:18,484 DEBUG DefaultLoadEventListener: loading entity: [org.lds.stack.petstore.model.Country#1]
10:44:18,484 DEBUG DefaultLoadEventListener: attempting to resolve: [org.lds.stack.petstore.model.Country#1]
10:44:18,484 DEBUG DefaultLoadEventListener: resolved object in session cache: [org.lds.stack.petstore.model.Country#1]
10:44:18,484 DEBUG Loader: result set row: 2
10:44:18,484 DEBUG LongType: returning '1' as column: id3_0_
10:44:18,484 DEBUG Loader: result row: EntityKey[org.lds.stack.petstore.model.Country#1]
10:44:18,484 DEBUG LongType: returning '24' as column: ANIMAL1_1_
10:44:18,484 DEBUG Loader: found row of collection: [org.lds.stack.petstore.model.Animal.countries#24]
10:44:18,484 DEBUG CollectionLoadContext: new collection: instantiating
10:44:18,484 DEBUG LongType: returning '1' as column: COUNTRY2_1_
10:44:18,484 DEBUG DefaultLoadEventListener: loading entity: [org.lds.stack.petstore.model.Country#1]
10:44:18,484 DEBUG DefaultLoadEventListener: attempting to resolve: [org.lds.stack.petstore.model.Country#1]
10:44:18,484 DEBUG DefaultLoadEventListener: resolved object in session cache: [org.lds.stack.petstore.model.Country#1]
10:44:18,484 DEBUG Loader: result set row: 3
10:44:18,484 DEBUG LongType: returning '1' as column: id3_0_
10:44:18,484 DEBUG Loader: result row: EntityKey[org.lds.stack.petstore.model.Country#1]
10:44:18,484 DEBUG LongType: returning '54' as column: ANIMAL1_1_
10:44:18,484 DEBUG Loader: found row of collection: [org.lds.stack.petstore.model.Animal.countries#54]
10:44:18,484 DEBUG CollectionLoadContext: new collection: instantiating
10:44:18,484 DEBUG LongType: returning '1' as column: COUNTRY2_1_
10:44:18,484 DEBUG DefaultLoadEventListener: loading entity: [org.lds.stack.petstore.model.Country#1]
10:44:18,484 DEBUG DefaultLoadEventListener: attempting to resolve: [org.lds.stack.petstore.model.Country#1]
10:44:18,484 DEBUG DefaultLoadEventListener: resolved object in session cache: [org.lds.stack.petstore.model.Country#1]
10:44:18,484 DEBUG Loader: result set row: 4
10:44:18,484 DEBUG LongType: returning '1' as column: id3_0_
10:44:18,484 DEBUG Loader: result row: EntityKey[org.lds.stack.petstore.model.Country#1]
10:44:18,484 DEBUG LongType: returning '55' as column: ANIMAL1_1_
10:44:18,484 DEBUG Loader: found row of collection: [org.lds.stack.petstore.model.Animal.countries#55]
10:44:18,484 DEBUG CollectionLoadContext: new collection: instantiating
10:44:18,484 DEBUG LongType: returning '1' as column: COUNTRY2_1_
10:44:18,484 DEBUG DefaultLoadEventListener: loading entity: [org.lds.stack.petstore.model.Country#1]
10:44:18,484 DEBUG DefaultLoadEventListener: attempting to resolve: [org.lds.stack.petstore.model.Country#1]
10:44:18,484 DEBUG DefaultLoadEventListener: resolved object in session cache: [org.lds.stack.petstore.model.Country#1]
10:44:18,484 DEBUG Loader: result set row: 5
10:44:18,484 DEBUG LongType: returning '1' as column: id3_0_
10:44:18,484 DEBUG Loader: result row: EntityKey[org.lds.stack.petstore.model.Country#1]
10:44:18,484 DEBUG LongType: returning '53' as column: ANIMAL1_1_
10:44:18,484 DEBUG Loader: found row of collection: [org.lds.stack.petstore.model.Animal.countries#53]
10:44:18,484 DEBUG CollectionLoadContext: new collection: instantiating
10:44:18,484 DEBUG LongType: returning '1' as column: COUNTRY2_1_
10:44:18,484 DEBUG DefaultLoadEventListener: loading entity: [org.lds.stack.petstore.model.Country#1]
10:44:18,484 DEBUG DefaultLoadEventListener: attempting to resolve: [org.lds.stack.petstore.model.Country#1]
10:44:18,484 DEBUG DefaultLoadEventListener: resolved object in session cache: [org.lds.stack.petstore.model.Country#1]
10:44:18,484 DEBUG Loader: result set row: 6
10:44:18,484 DEBUG LongType: returning '1' as column: id3_0_
10:44:18,484 DEBUG Loader: result row: EntityKey[org.lds.stack.petstore.model.Country#1]
10:44:18,484 DEBUG LongType: returning '52' as column: ANIMAL1_1_
10:44:18,484 DEBUG Loader: found row of collection: [org.lds.stack.petstore.model.Animal.countries#52]
10:44:18,484 DEBUG CollectionLoadContext: new collection: instantiating
10:44:18,484 DEBUG LongType: returning '1' as column: COUNTRY2_1_
10:44:18,484 DEBUG DefaultLoadEventListener: loading entity: [org.lds.stack.petstore.model.Country#1]
10:44:18,484 DEBUG DefaultLoadEventListener: attempting to resolve: [org.lds.stack.petstore.model.Country#1]
10:44:18,484 DEBUG DefaultLoadEventListener: resolved object in session cache: [org.lds.stack.petstore.model.Country#1]
10:44:18,484 DEBUG Loader: result set row: 7
10:44:18,484 DEBUG LongType: returning '1' as column: id3_0_
10:44:18,484 DEBUG Loader: result row: EntityKey[org.lds.stack.petstore.model.Country#1]
10:44:18,484 DEBUG LongType: returning '505' as column: ANIMAL1_1_
10:44:18,484 DEBUG Loader: found row of collection: [org.lds.stack.petstore.model.Animal.countries#505]
10:44:18,484 DEBUG CollectionLoadContext: reading row
10:44:18,484 DEBUG LongType: returning '1' as column: COUNTRY2_1_
10:44:18,484 DEBUG DefaultLoadEventListener: loading entity: [org.lds.stack.petstore.model.Country#1]
10:44:18,484 DEBUG DefaultLoadEventListener: attempting to resolve: [org.lds.stack.petstore.model.Country#1]
10:44:18,484 DEBUG DefaultLoadEventListener: resolved object in session cache: [org.lds.stack.petstore.model.Country#1]
10:44:18,484 DEBUG Loader: result set row: 8
10:44:18,484 DEBUG LongType: returning '2' as column: id3_0_
10:44:18,484 DEBUG Loader: result row: EntityKey[org.lds.stack.petstore.model.Country#2]
10:44:18,484 DEBUG Loader: Initializing object from ResultSet: [org.lds.stack.petstore.model.Country#2]
10:44:18,484 DEBUG AbstractEntityPersister: Hydrating entity: [org.lds.stack.petstore.model.Country#2]
10:44:18,484 DEBUG StringType: returning 'Albania' as column: name3_0_
10:44:18,484 DEBUG LongType: returning '19' as column: ANIMAL1_1_
10:44:18,484 DEBUG Loader: found row of collection: [org.lds.stack.petstore.model.Animal.countries#19]
10:44:18,484 DEBUG CollectionLoadContext: reading row
10:44:18,484 DEBUG LongType: returning '2' as column: COUNTRY2_1_
10:44:18,484 DEBUG DefaultLoadEventListener: loading entity: [org.lds.stack.petstore.model.Country#2]
10:44:18,484 DEBUG DefaultLoadEventListener: attempting to resolve: [org.lds.stack.petstore.model.Country#2]
10:44:18,484 DEBUG DefaultLoadEventListener: resolved object in session cache: [org.lds.stack.petstore.model.Country#2]
10:44:18,484 DEBUG Loader: result set row: 9
10:44:18,484 DEBUG LongType: returning '2' as column: id3_0_
10:44:18,484 DEBUG Loader: result row: EntityKey[org.lds.stack.petstore.model.Country#2]
10:44:18,484 DEBUG LongType: returning '23' as column: ANIMAL1_1_
10:44:18,484 DEBUG Loader: found row of collection: [org.lds.stack.petstore.model.Animal.countries#23]
10:44:18,484 DEBUG CollectionLoadContext: reading row
10:44:18,484 DEBUG LongType: returning '2' as column: COUNTRY2_1_
10:44:18,484 DEBUG DefaultLoadEventListener: loading entity: [org.lds.stack.petstore.model.Country#2]
10:44:18,484 DEBUG DefaultLoadEventListener: attempting to resolve: [org.lds.stack.petstore.model.Country#2]
10:44:18,484 DEBUG DefaultLoadEventListener: resolved object in session cache: [org.lds.stack.petstore.model.Country#2]
10:44:18,484 DEBUG Loader: result set row: 10
10:44:18,484 DEBUG LongType: returning '4' as column: id3_0_
10:44:18,484 DEBUG Loader: result row: EntityKey[org.lds.stack.petstore.model.Country#4]
10:44:18,484 DEBUG Loader: Initializing object from ResultSet: [org.lds.stack.petstore.model.Country#4]
10:44:18,484 DEBUG AbstractEntityPersister: Hydrating entity: [org.lds.stack.petstore.model.Country#4]
10:44:18,484 DEBUG StringType: returning 'American Samoa' as column: name3_0_
10:44:18,484 DEBUG LongType: returning '19' as column: ANIMAL1_1_
10:44:18,484 DEBUG Loader: found row of collection: [org.lds.stack.petstore.model.Animal.countries#19]
10:44:18,484 DEBUG CollectionLoadContext: reading row
10:44:18,484 DEBUG LongType: returning '4' as column: COUNTRY2_1_
10:44:18,484 DEBUG DefaultLoadEventListener: loading entity: [org.lds.stack.petstore.model.Country#4]
10:44:18,484 DEBUG DefaultLoadEventListener: attempting to resolve: [org.lds.stack.petstore.model.Country#4]
10:44:18,484 DEBUG DefaultLoadEventListener: resolved object in session cache: [org.lds.stack.petstore.model.Country#4]
10:44:18,484 DEBUG Loader: result set row: 11
10:44:18,484 DEBUG LongType: returning '7' as column: id3_0_
10:44:18,484 DEBUG Loader: result row: EntityKey[org.lds.stack.petstore.model.Country#7]
10:44:18,484 DEBUG Loader: Initializing object from ResultSet: [org.lds.stack.petstore.model.Country#7]
10:44:18,484 DEBUG AbstractEntityPersister: Hydrating entity: [org.lds.stack.petstore.model.Country#7]
10:44:18,484 DEBUG StringType: returning 'Anguilla' as column: name3_0_
10:44:18,484 DEBUG LongType: returning '49' as column: ANIMAL1_1_
10:44:18,484 DEBUG Loader: found row of collection: [org.lds.stack.petstore.model.Animal.countries#49]
10:44:18,484 DEBUG CollectionLoadContext: new collection: instantiating
10:44:18,484 DEBUG LongType: returning '7' as column: COUNTRY2_1_
10:44:18,484 DEBUG DefaultLoadEventListener: loading entity: [org.lds.stack.petstore.model.Country#7]
10:44:18,484 DEBUG DefaultLoadEventListener: attempting to resolve: [org.lds.stack.petstore.model.Country#7]
10:44:18,484 DEBUG DefaultLoadEventListener: resolved object in session cache: [org.lds.stack.petstore.model.Country#7]
10:44:18,484 DEBUG Loader: result set row: 12
10:44:18,484 DEBUG LongType: returning '8' as column: id3_0_
10:44:18,484 DEBUG Loader: result row: EntityKey[org.lds.stack.petstore.model.Country#8]
10:44:18,484 DEBUG Loader: Initializing object from ResultSet: [org.lds.stack.petstore.model.Country#8]
10:44:18,484 DEBUG AbstractEntityPersister: Hydrating entity: [org.lds.stack.petstore.model.Country#8]
10:44:18,484 DEBUG StringType: returning 'Antarctica' as column: name3_0_
10:44:18,484 DEBUG LongType: returning '49' as column: ANIMAL1_1_
10:44:18,484 DEBUG Loader: found row of collection: [org.lds.stack.petstore.model.Animal.countries#49]
10:44:18,484 DEBUG CollectionLoadContext: reading row
10:44:18,484 DEBUG LongType: returning '8' as column: COUNTRY2_1_
10:44:18,484 DEBUG DefaultLoadEventListener: loading entity: [org.lds.stack.petstore.model.Country#8]
10:44:18,484 DEBUG DefaultLoadEventListener: attempting to resolve: [org.lds.stack.petstore.model.Country#8]
10:44:18,484 DEBUG DefaultLoadEventListener: resolved object in session cache: [org.lds.stack.petstore.model.Country#8]
10:44:18,484 DEBUG Loader: result set row: 13
10:44:18,484 DEBUG LongType: returning '9' as column: id3_0_
10:44:18,484 DEBUG Loader: result row: EntityKey[org.lds.stack.petstore.model.Country#9]
10:44:18,484 DEBUG Loader: Initializing object from ResultSet: [org.lds.stack.petstore.model.Country#9]
10:44:18,484 DEBUG AbstractEntityPersister: Hydrating entity: [org.lds.stack.petstore.model.Country#9]
10:44:18,484 DEBUG StringType: returning 'Antigua And Barbuda' as column: name3_0_
10:44:18,484 DEBUG LongType: returning '49' as column: ANIMAL1_1_
10:44:18,484 DEBUG Loader: found row of collection: [org.lds.stack.petstore.model.Animal.countries#49]
10:44:18,484 DEBUG CollectionLoadContext: reading row
10:44:18,484 DEBUG LongType: returning '9' as column: COUNTRY2_1_
10:44:18,484 DEBUG DefaultLoadEventListener: loading entity: [org.lds.stack.petstore.model.Country#9]
10:44:18,484 DEBUG DefaultLoadEventListener: attempting to resolve: [org.lds.stack.petstore.model.Country#9]
10:44:18,484 DEBUG DefaultLoadEventListener: resolved object in session cache: [org.lds.stack.petstore.model.Country#9]
10:44:18,484 DEBUG Loader: result set row: 14
10:44:18,484 DEBUG LongType: returning '10' as column: id3_0_
10:44:18,484 DEBUG Loader: result row: EntityKey[org.lds.stack.petstore.model.Country#10]
10:44:18,484 DEBUG Loader: Initializing object from ResultSet: [org.lds.stack.petstore.model.Country#10]
10:44:18,484 DEBUG AbstractEntityPersister: Hydrating entity: [org.lds.stack.petstore.model.Country#10]
10:44:18,484 DEBUG StringType: returning 'Argentina' as column: name3_0_
10:44:18,484 DEBUG LongType: returning '19' as column: ANIMAL1_1_
10:44:18,484 DEBUG Loader: found row of collection: [org.lds.stack.petstore.model.Animal.countries#19]
10:44:18,484 DEBUG CollectionLoadContext: reading row
10:44:18,484 DEBUG LongType: returning '10' as column: COUNTRY2_1_
10:44:18,484 DEBUG DefaultLoadEventListener: loading entity: [org.lds.stack.petstore.model.Country#10]
10:44:18,484 DEBUG DefaultLoadEventListener: attempting to resolve: [org.lds.stack.petstore.model.Country#10]
10:44:18,484 DEBUG DefaultLoadEventListener: resolved object in session cache: [org.lds.stack.petstore.model.Country#10]
10:44:18,484 DEBUG Loader: result set row: 15
10:44:18,484 DEBUG LongType: returning '10' as column: id3_0_
10:44:18,484 DEBUG Loader: result row: EntityKey[org.lds.stack.petstore.model.Country#10]
10:44:18,484 DEBUG LongType: returning '20' as column: ANIMAL1_1_
10:44:18,484 DEBUG Loader: found row of collection: [org.lds.stack.petstore.model.Animal.countries#20]
10:44:18,484 DEBUG CollectionLoadContext: new collection: instantiating
10:44:18,484 DEBUG LongType: returning '10' as column: COUNTRY2_1_
10:44:18,484 DEBUG DefaultLoadEventListener: loading entity: [org.lds.stack.petstore.model.Country#10]
10:44:18,484 DEBUG DefaultLoadEventListener: attempting to resolve: [org.lds.stack.petstore.model.Country#10]
10:44:18,484 DEBUG DefaultLoadEventListener: resolved object in session cache: [org.lds.stack.petstore.model.Country#10]
10:44:18,484 DEBUG Loader: result set row: 16
10:44:18,484 DEBUG LongType: returning '12' as column: id3_0_
10:44:18,484 DEBUG Loader: result row: EntityKey[org.lds.stack.petstore.model.Country#12]
10:44:18,484 DEBUG Loader: Initializing object from ResultSet: [org.lds.stack.petstore.model.Country#12]
10:44:18,484 DEBUG AbstractEntityPersister: Hydrating entity: [org.lds.stack.petstore.model.Country#12]
10:44:18,484 DEBUG StringType: returning 'Aruba' as column: name3_0_
10:44:18,484 DEBUG LongType: returning '18' as column: ANIMAL1_1_
10:44:18,484 DEBUG Loader: found row of collection: [org.lds.stack.petstore.model.Animal.countries#18]
10:44:18,484 DEBUG CollectionLoadContext: new collection: instantiating
10:44:18,484 DEBUG LongType: returning '12' as column: COUNTRY2_1_
10:44:18,484 DEBUG DefaultLoadEventListener: loading entity: [org.lds.stack.petstore.model.Country#12]
10:44:18,484 DEBUG DefaultLoadEventListener: attempting to resolve: [org.lds.stack.petstore.model.Country#12]
10:44:18,484 DEBUG DefaultLoadEventListener: resolved object in session cache: [org.lds.stack.petstore.model.Country#12]
10:44:18,484 DEBUG Loader: result set row: 17
10:44:18,484 DEBUG LongType: returning '15' as column: id3_0_
10:44:18,484 DEBUG Loader: result row: EntityKey[org.lds.stack.petstore.model.Country#15]
10:44:18,484 DEBUG Loader: Initializing object from ResultSet: [org.lds.stack.petstore.model.Country#15]
10:44:18,484 DEBUG AbstractEntityPersister: Hydrating entity: [org.lds.stack.petstore.model.Country#15]
10:44:18,484 DEBUG StringType: returning 'Azerbaijan' as column: name3_0_
10:44:18,484 DEBUG LongType: returning '50' as column: ANIMAL1_1_
10:44:18,484 DEBUG Loader: found row of collection: [org.lds.stack.petstore.model.Animal.countries#50]
10:44:18,484 DEBUG CollectionLoadContext: new collection: instantiating
10:44:18,484 DEBUG LongType: returning '15' as column: COUNTRY2_1_
10:44:18,484 DEBUG DefaultLoadEventListener: loading entity: [org.lds.stack.petstore.model.Country#15]
10:44:18,484 DEBUG DefaultLoadEventListener: attempting to resolve: [org.lds.stack.petstore.model.Country#15]
10:44:18,484 DEBUG DefaultLoadEventListener: resolved object in session cache: [org.lds.stack.petstore.model.Country#15]
10:44:18,484 DEBUG Loader: result set row: 18
10:44:18,484 DEBUG LongType: returning '16' as column: id3_0_
10:44:18,484 DEBUG Loader: result row: EntityKey[org.lds.stack.petstore.model.Country#16]
10:44:18,484 DEBUG Loader: Initializing object from ResultSet: [org.lds.stack.petstore.model.Country#16]
10:44:18,484 DEBUG AbstractEntityPersister: Hydrating entity: [org.lds.stack.petstore.model.Country#16]
10:44:18,484 DEBUG StringType: returning 'Bahamas' as column: name3_0_
10:44:18,484 DEBUG LongType: returning '21' as column: ANIMAL1_1_
10:44:18,484 DEBUG Loader: found row of collection: [org.lds.stack.petstore.model.Animal.countries#21]
10:44:18,484 DEBUG CollectionLoadContext: new collection: instantiating
10:44:18,484 DEBUG LongType: returning '16' as column: COUNTRY2_1_
10:44:18,484 DEBUG DefaultLoadEventListener: loading entity: [org.lds.stack.petstore.model.Country#16]
10:44:18,484 DEBUG DefaultLoadEventListener: attempting to resolve: [org.lds.stack.petstore.model.Country#16]
10:44:18,484 DEBUG DefaultLoadEventListener: resolved object in session cache: [org.lds.stack.petstore.model.Country#16]
10:44:18,484 DEBUG Loader: result set row: 19
10:44:18,484 DEBUG LongType: returning '16' as column: id3_0_
10:44:18,484 DEBUG Loader: result row: EntityKey[org.lds.stack.petstore.model.Country#16]
10:44:18,484 DEBUG LongType: returning '50' as column: ANIMAL1_1_
10:44:18,484 DEBUG Loader: found row of collection: [org.lds.stack.petstore.model.Animal.countries#50]
10:44:18,484 DEBUG CollectionLoadContext: reading row
10:44:18,484 DEBUG LongType: returning '16' as column: COUNTRY2_1_
10:44:18,484 DEBUG DefaultLoadEventListener: loading entity: [org.lds.stack.petstore.model.Country#16]
10:44:18,484 DEBUG DefaultLoadEventListener: attempting to resolve: [org.lds.stack.petstore.model.Country#16]
10:44:18,484 DEBUG DefaultLoadEventListener: resolved object in session cache: [org.lds.stack.petstore.model.Country#16]
10:44:18,484 DEBUG Loader: result set row: 20
10:44:18,500 DEBUG LongType: returning '17' as column: id3_0_
10:44:18,500 DEBUG Loader: result row: EntityKey[org.lds.stack.petstore.model.Country#17]
10:44:18,500 DEBUG Loader: Initializing object from ResultSet: [org.lds.stack.petstore.model.Country#17]
10:44:18,500 DEBUG AbstractEntityPersister: Hydrating entity: [org.lds.stack.petstore.model.Country#17]
10:44:18,500 DEBUG StringType: returning 'Bahrain' as column: name3_0_
10:44:18,500 DEBUG LongType: returning '50' as column: ANIMAL1_1_
10:44:18,500 DEBUG Loader: found row of collection: [org.lds.stack.petstore.model.Animal.countries#50]
10:44:18,500 DEBUG CollectionLoadContext: reading row
10:44:18,500 DEBUG LongType: returning '17' as column: COUNTRY2_1_
10:44:18,500 DEBUG DefaultLoadEventListener: loading entity: [org.lds.stack.petstore.model.Country#17]
10:44:18,500 DEBUG DefaultLoadEventListener: attempting to resolve: [org.lds.stack.petstore.model.Country#17]
10:44:18,500 DEBUG DefaultLoadEventListener: resolved object in session cache: [org.lds.stack.petstore.model.Country#17]
10:44:18,500 DEBUG Loader: result set row: 21
10:44:18,500 DEBUG LongType: returning '22' as column: id3_0_
10:44:18,500 DEBUG Loader: result row: EntityKey[org.lds.stack.petstore.model.Country#22]
10:44:18,500 DEBUG Loader: Initializing object from ResultSet: [org.lds.stack.petstore.model.Country#22]
10:44:18,500 DEBUG AbstractEntityPersister: Hydrating entity: [org.lds.stack.petstore.model.Country#22]
10:44:18,500 DEBUG StringType: returning 'Belize' as column: name3_0_
10:44:18,500 DEBUG LongType: returning '47' as column: ANIMAL1_1_
10:44:18,500 DEBUG Loader: found row of collection: [org.lds.stack.petstore.model.Animal.countries#47]
10:44:18,500 DEBUG CollectionLoadContext: new collection: instantiating
10:44:18,500 DEBUG LongType: returning '22' as column: COUNTRY2_1_
10:44:18,500 DEBUG DefaultLoadEventListener: loading entity: [org.lds.stack.petstore.model.Country#22]
10:44:18,500 DEBUG DefaultLoadEventListener: attempting to resolve: [org.lds.stack.petstore.model.Country#22]
10:44:18,500 DEBUG DefaultLoadEventListener: resolved object in session cache: [org.lds.stack.petstore.model.Country#22]
10:44:18,500 DEBUG Loader: result set row: 22
10:44:18,500 DEBUG LongType: returning '27' as column: id3_0_
10:44:18,500 DEBUG Loader: result row: EntityKey[org.lds.stack.petstore.model.Country#27]
10:44:18,500 DEBUG Loader: Initializing object from ResultSet: [org.lds.stack.petstore.model.Country#27]
10:44:18,500 DEBUG AbstractEntityPersister: Hydrating entity: [org.lds.stack.petstore.model.Country#27]
10:44:18,500 DEBUG StringType: returning 'Bosnia And Herzegovina' as column: name3_0_
10:44:18,500 DEBUG LongType: returning '46' as column: ANIMAL1_1_
10:44:18,500 DEBUG Loader: found row of collection: [org.lds.stack.petstore.model.Animal.countries#46]
10:44:18,500 DEBUG CollectionLoadContext: new collection: instantiating
10:44:18,500 DEBUG LongType: returning '27' as column: COUNTRY2_1_
10:44:18,500 DEBUG DefaultLoadEventListener: loading entity: [org.lds.stack.petstore.model.Country#27]
10:44:18,500 DEBUG DefaultLoadEventListener: attempting to resolve: [org.lds.stack.petstore.model.Country#27]
10:44:18,500 DEBUG DefaultLoadEventListener: resolved object in session cache: [org.lds.stack.petstore.model.Country#27]
10:44:18,500 DEBUG Loader: result set row: 23
10:44:18,500 DEBUG LongType: returning '29' as column: id3_0_
10:44:18,500 DEBUG Loader: result row: EntityKey[org.lds.stack.petstore.model.Country#29]
10:44:18,500 DEBUG Loader: Initializing object from ResultSet: [org.lds.stack.petstore.model.Country#29]
10:44:18,500 DEBUG AbstractEntityPersister: Hydrating entity: [org.lds.stack.petstore.model.Country#29]
10:44:18,500 DEBUG StringType: returning 'Bouvet Island' as column: name3_0_
10:44:18,500 DEBUG LongType: returning '45' as column: ANIMAL1_1_
10:44:18,500 DEBUG Loader: found row of collection: [org.lds.stack.petstore.model.Animal.countries#45]
10:44:18,500 DEBUG CollectionLoadContext: new collection: instantiating
10:44:18,500 DEBUG LongType: returning '29' as column: COUNTRY2_1_
10:44:18,500 DEBUG DefaultLoadEventListener: loading entity: [org.lds.stack.petstore.model.Country#29]
10:44:18,500 DEBUG DefaultLoadEventListener: attempting to resolve: [org.lds.stack.petstore.model.Country#29]
10:44:18,500 DEBUG DefaultLoadEventListener: resolved object in session cache: [org.lds.stack.petstore.model.Country#29]
10:44:18,500 DEBUG Loader: result set row: 24
10:44:18,500 DEBUG LongType: returning '33' as column: id3_0_
10:44:18,500 DEBUG Loader: result row: EntityKey[org.lds.stack.petstore.model.Country#33]
10:44:18,500 DEBUG Loader: Initializing object from ResultSet: [org.lds.stack.petstore.model.Country#33]
10:44:18,500 DEBUG AbstractEntityPersister: Hydrating entity: [org.lds.stack.petstore.model.Country#33]
10:44:18,500 DEBUG StringType: returning 'Bulgaria' as column: name3_0_
10:44:18,500 DEBUG LongType: returning '43' as column: ANIMAL1_1_
10:44:18,500 DEBUG Loader: found row of collection: [org.lds.stack.petstore.model.Animal.countries#43]
10:44:18,500 DEBUG CollectionLoadContext: new collection: instantiating
10:44:18,500 DEBUG LongType: returning '33' as column: COUNTRY2_1_
10:44:18,500 DEBUG DefaultLoadEventListener: loading entity: [org.lds.stack.petstore.model.Country#33]
10:44:18,500 DEBUG DefaultLoadEventListener: attempting to resolve: [org.lds.stack.petstore.model.Country#33]
10:44:18,500 DEBUG DefaultLoadEventListener: resolved object in session cache: [org.lds.stack.petstore.model.Country#33]
10:44:18,500 DEBUG Loader: result set row: 25
10:44:18,500 DEBUG LongType: returning '38' as column: id3_0_
10:44:18,500 DEBUG Loader: result row: EntityKey[org.lds.stack.petstore.model.Country#38]
10:44:18,500 DEBUG Loader: Initializing object from ResultSet: [org.lds.stack.petstore.model.Country#38]
10:44:18,500 DEBUG AbstractEntityPersister: Hydrating entity: [org.lds.stack.petstore.model.Country#38]
10:44:18,500 DEBUG StringType: returning 'Canada' as column: name3_0_
10:44:18,500 DEBUG LongType: returning '1' as column: ANIMAL1_1_
10:44:18,500 DEBUG Loader: found row of collection: [org.lds.stack.petstore.model.Animal.countries#1]
10:44:18,500 DEBUG CollectionLoadContext: new collection: instantiating
10:44:18,500 DEBUG LongType: returning '38' as column: COUNTRY2_1_
10:44:18,500 DEBUG DefaultLoadEventListener: loading entity: [org.lds.stack.petstore.model.Country#38]
10:44:18,500 DEBUG DefaultLoadEventListener: attempting to resolve: [org.lds.stack.petstore.model.Country#38]
10:44:18,500 DEBUG DefaultLoadEventListener: resolved object in session cache: [org.lds.stack.petstore.model.Country#38]
10:44:18,500 DEBUG Loader: result set row: 26
10:44:18,500 DEBUG LongType: returning '38' as column: id3_0_
10:44:18,500 DEBUG Loader: result row: EntityKey[org.lds.stack.petstore.model.Country#38]
10:44:18,500 DEBUG LongType: returning '2' as column: ANIMAL1_1_
10:44:18,500 DEBUG Loader: found row of collection: [org.lds.stack.petstore.model.Animal.countries#2]
10:44:18,500 DEBUG CollectionLoadContext: new collection: instantiating
10:44:18,500 DEBUG LongType: returning '38' as column: COUNTRY2_1_
10:44:18,500 DEBUG DefaultLoadEventListener: loading entity: [org.lds.stack.petstore.model.Country#38]
10:44:18,500 DEBUG DefaultLoadEventListener: attempting to resolve: [org.lds.stack.petstore.model.Country#38]
10:44:18,500 DEBUG DefaultLoadEventListener: resolved object in session cache: [org.lds.stack.petstore.model.Country#38]
10:44:18,500 DEBUG Loader: result set row: 27
10:44:18,500 DEBUG LongType: returning '38' as column: id3_0_
10:44:18,500 DEBUG Loader: result row: EntityKey[org.lds.stack.petstore.model.Country#38]
10:44:18,500 DEBUG LongType: returning '4' as column: ANIMAL1_1_
10:44:18,500 DEBUG Loader: found row of collection: [org.lds.stack.petstore.model.Animal.countries#4]
10:44:18,500 DEBUG CollectionLoadContext: new collection: instantiating
10:44:18,500 DEBUG LongType: returning '38' as column: COUNTRY2_1_
10:44:18,500 DEBUG DefaultLoadEventListener: loading entity: [org.lds.stack.petstore.model.Country#38]
10:44:18,500 DEBUG DefaultLoadEventListener: attempting to resolve: [org.lds.stack.petstore.model.Country#38]
10:44:18,500 DEBUG DefaultLoadEventListener: resolved object in session cache: [org.lds.stack.petstore.model.Country#38]
10:44:18,500 DEBUG Loader: result set row: 28
10:44:18,500 DEBUG LongType: returning '38' as column: id3_0_
10:44:18,500 DEBUG Loader: result row: EntityKey[org.lds.stack.petstore.model.Country#38]
10:44:18,500 DEBUG LongType: returning '6' as column: ANIMAL1_1_
10:44:18,500 DEBUG Loader: found row of collection: [org.lds.stack.petstore.model.Animal.countries#6]
10:44:18,500 DEBUG CollectionLoadContext: new collection: instantiating
10:44:18,500 DEBUG LongType: returning '38' as column: COUNTRY2_1_
10:44:18,500 DEBUG DefaultLoadEventListener: loading entity: [org.lds.stack.petstore.model.Country#38]
10:44:18,500 DEBUG DefaultLoadEventListener: attempting to resolve: [org.lds.stack.petstore.model.Country#38]
10:44:18,500 DEBUG DefaultLoadEventListener: resolved object in session cache: [org.lds.stack.petstore.model.Country#38]
10:44:18,500 DEBUG Loader: result set row: 29
10:44:18,500 DEBUG LongType: returning '38' as column: id3_0_
10:44:18,500 DEBUG Loader: result row: EntityKey[org.lds.stack.petstore.model.Country#38]
10:44:18,500 DEBUG LongType: returning '8' as column: ANIMAL1_1_
10:44:18,500 DEBUG Loader: found row of collection: [org.lds.stack.petstore.model.Animal.countries#8]
10:44:18,500 DEBUG CollectionLoadContext: new collection: instantiating
10:44:18,500 DEBUG LongType: returning '38' as column: COUNTRY2_1_
10:44:18,500 DEBUG DefaultLoadEventListener: loading entity: [org.lds.stack.petstore.model.Country#38]
10:44:18,500 DEBUG DefaultLoadEventListener: attempting to resolve: [org.lds.stack.petstore.model.Country#38]
10:44:18,500 DEBUG DefaultLoadEventListener: resolved object in session cache: [org.lds.stack.petstore.model.Country#38]
10:44:18,500 DEBUG Loader: result set row: 30
10:44:18,500 DEBUG LongType: returning '38' as column: id3_0_
10:44:18,500 DEBUG Loader: result row: EntityKey[org.lds.stack.petstore.model.Country#38]
10:44:18,500 DEBUG LongType: returning '10' as column: ANIMAL1_1_
10:44:18,500 DEBUG Loader: found row of collection: [org.lds.stack.petstore.model.Animal.countries#10]
10:44:18,500 DEBUG CollectionLoadContext: new collection: instantiating
10:44:18,500 DEBUG LongType: returning '38' as column: COUNTRY2_1_
10:44:18,500 DEBUG DefaultLoadEventListener: loading entity: [org.lds.stack.petstore.model.Country#38]
10:44:18,500 DEBUG DefaultLoadEventListener: attempting to resolve: [org.lds.stack.petstore.model.Country#38]
10:44:18,500 DEBUG DefaultLoadEventListener: resolved object in session cache: [org.lds.stack.petstore.model.Country#38]
10:44:18,500 DEBUG Loader: result set row: 31
10:44:18,500 DEBUG LongType: returning '38' as column: id3_0_
10:44:18,500 DEBUG Loader: result row: EntityKey[org.lds.stack.petstore.model.Country#38]
10:44:18,500 DEBUG LongType: returning '12' as column: ANIMAL1_1_
10:44:18,500 DEBUG Loader: found row of collection: [org.lds.stack.petstore.model.Animal.countries#12]
10:44:18,500 DEBUG CollectionLoadContext: new collection: instantiating
10:44:18,500 DEBUG LongType: returning '38' as column: COUNTRY2_1_
10:44:18,500 DEBUG DefaultLoadEventListener: loading entity: [org.lds.stack.petstore.model.Country#38]
10:44:18,500 DEBUG DefaultLoadEventListener: attempting to resolve: [org.lds.stack.petstore.model.Country#38]
10:44:18,500 DEBUG DefaultLoadEventListener: resolved object in session cache: [org.lds.stack.petstore.model.Country#38]
10:44:18,500 DEBUG Loader: result set row: 32
10:44:18,500 DEBUG LongType: returning '38' as column: id3_0_
10:44:18,500 DEBUG Loader: result row: EntityKey[org.lds.stack.petstore.model.Country#38]
10:44:18,500 DEBUG LongType: returning '14' as column: ANIMAL1_1_
10:44:18,500 DEBUG Loader: found row of collection: [org.lds.stack.petstore.model.Animal.countries#14]
10:44:18,500 DEBUG CollectionLoadContext: new collection: instantiating
10:44:18,500 DEBUG LongType: returning '38' as column: COUNTRY2_1_
10:44:18,500 DEBUG DefaultLoadEventListener: loading entity: [org.lds.stack.petstore.model.Country#38]
10:44:18,500 DEBUG DefaultLoadEventListener: attempting to resolve: [org.lds.stack.petstore.model.Country#38]
10:44:18,500 DEBUG DefaultLoadEventListener: resolved object in session cache: [org.lds.stack.petstore.model.Country#38]
10:44:18,500 DEBUG Loader: result set row: 33
10:44:18,500 DEBUG LongType: returning '38' as column: id3_0_
10:44:18,500 DEBUG Loader: result row: EntityKey[org.lds.stack.petstore.model.Country#38]
10:44:18,500 DEBUG LongType: returning '16' as column: ANIMAL1_1_
10:44:18,500 DEBUG Loader: found row of collection: [org.lds.stack.petstore.model.Animal.countries#16]
10:44:18,500 DEBUG CollectionLoadContext: new collection: instantiating
10:44:18,500 DEBUG LongType: returning '38' as column: COUNTRY2_1_
10:44:18,500 DEBUG DefaultLoadEventListener: loading entity: [org.lds.stack.petstore.model.Country#38]
10:44:18,500 DEBUG DefaultLoadEventListener: attempting to resolve: [org.lds.stack.petstore.model.Country#38]
10:44:18,500 DEBUG DefaultLoadEventListener: resolved object in session cache: [org.lds.stack.petstore.model.Country#38]
10:44:18,500 DEBUG Loader: result set row: 34
10:44:18,500 DEBUG LongType: returning '38' as column: id3_0_
10:44:18,500 DEBUG Loader: result row: EntityKey[org.lds.stack.petstore.model.Country#38]
10:44:18,500 DEBUG LongType: returning '15' as column: ANIMAL1_1_
10:44:18,500 DEBUG Loader: found row of collection: [org.lds.stack.petstore.model.Animal.countries#15]
10:44:18,500 DEBUG CollectionLoadContext: reading row
10:44:18,500 DEBUG LongType: returning '38' as column: COUNTRY2_1_
10:44:18,500 DEBUG DefaultLoadEventListener: loading entity: [org.lds.stack.petstore.model.Country#38]
10:44:18,500 DEBUG DefaultLoadEventListener: attempting to resolve: [org.lds.stack.petstore.model.Country#38]
10:44:18,500 DEBUG DefaultLoadEventListener: resolved object in session cache: [org.lds.stack.petstore.model.Country#38]
10:44:18,500 DEBUG Loader: result set row: 35
10:44:18,500 DEBUG LongType: returning '38' as column: id3_0_
10:44:18,500 DEBUG Loader: result row: EntityKey[org.lds.stack.petstore.model.Country#38]
10:44:18,500 DEBUG LongType: returning '13' as column: ANIMAL1_1_
10:44:18,500 DEBUG Loader: found row of collection: [org.lds.stack.petstore.model.Animal.countries#13]
10:44:18,500 DEBUG CollectionLoadContext: new collection: instantiating
10:44:18,500 DEBUG LongType: returning '38' as column: COUNTRY2_1_
10:44:18,500 DEBUG DefaultLoadEventListener: loading entity: [org.lds.stack.petstore.model.Country#38]
10:44:18,500 DEBUG DefaultLoadEventListener: attempting to resolve: [org.lds.stack.petstore.model.Country#38]
10:44:18,500 DEBUG DefaultLoadEventListener: resolved object in session cache: [org.lds.stack.petstore.model.Country#38]
10:44:18,500 DEBUG Loader: result set row: 36
10:44:18,500 DEBUG LongType: returning '38' as column: id3_0_
10:44:18,500 DEBUG Loader: result row: EntityKey[org.lds.stack.petstore.model.Country#38]
10:44:18,500 DEBUG LongType: returning '11' as column: ANIMAL1_1_
10:44:18,500 DEBUG Loader: found row of collection: [org.lds.stack.petstore.model.Animal.countries#11]
10:44:18,500 DEBUG CollectionLoadContext: new collection: instantiating
10:44:18,500 DEBUG LongType: returning '38' as column: COUNTRY2_1_
10:44:18,500 DEBUG DefaultLoadEventListener: loading entity: [org.lds.stack.petstore.model.Country#38]
10:44:18,500 DEBUG DefaultLoadEventListener: attempting to resolve: [org.lds.stack.petstore.model.Country#38]
10:44:18,500 DEBUG DefaultLoadEventListener: resolved object in session cache: [org.lds.stack.petstore.model.Country#38]
10:44:18,500 DEBUG Loader: result set row: 37
10:44:18,500 DEBUG LongType: returning '38' as column: id3_0_
10:44:18,500 DEBUG Loader: result row: EntityKey[org.lds.stack.petstore.model.Country#38]
10:44:18,500 DEBUG LongType: returning '9' as column: ANIMAL1_1_
10:44:18,500 DEBUG Loader: found row of collection: [org.lds.stack.petstore.model.Animal.countries#9]
10:44:18,500 DEBUG CollectionLoadContext: new collection: instantiating
10:44:18,500 DEBUG LongType: returning '38' as column: COUNTRY2_1_
10:44:18,500 DEBUG DefaultLoadEventListener: loading entity: [org.lds.stack.petstore.model.Country#38]
10:44:18,500 DEBUG DefaultLoadEventListener: attempting to resolve: [org.lds.stack.petstore.model.Country#38]
10:44:18,500 DEBUG DefaultLoadEventListener: resolved object in session cache: [org.lds.stack.petstore.model.Country#38]
10:44:18,500 DEBUG Loader: result set row: 38
10:44:18,500 DEBUG LongType: returning '38' as column: id3_0_
10:44:18,500 DEBUG Loader: result row: EntityKey[org.lds.stack.petstore.model.Country#38]
10:44:18,500 DEBUG LongType: returning '7' as column: ANIMAL1_1_
10:44:18,500 DEBUG Loader: found row of collection: [org.lds.stack.petstore.model.Animal.countries#7]
10:44:18,500 DEBUG CollectionLoadContext: new collection: instantiating
10:44:18,500 DEBUG LongType: returning '38' as column: COUNTRY2_1_
10:44:18,500 DEBUG DefaultLoadEventListener: loading entity: [org.lds.stack.petstore.model.Country#38]
10:44:18,500 DEBUG DefaultLoadEventListener: attempting to resolve: [org.lds.stack.petstore.model.Country#38]
10:44:18,500 DEBUG DefaultLoadEventListener: resolved object in session cache: [org.lds.stack.petstore.model.Country#38]
10:44:18,500 DEBUG Loader: result set row: 39
10:44:18,500 DEBUG LongType: returning '38' as column: id3_0_
10:44:18,500 DEBUG Loader: result row: EntityKey[org.lds.stack.petstore.model.Country#38]
10:44:18,500 DEBUG LongType: returning '5' as column: ANIMAL1_1_
10:44:18,500 DEBUG Loader: found row of collection: [org.lds.stack.petstore.model.Animal.countries#5]
10:44:18,500 DEBUG CollectionLoadContext: new collection: instantiating
10:44:18,500 DEBUG LongType: returning '38' as column: COUNTRY2_1_
10:44:18,500 DEBUG DefaultLoadEventListener: loading entity: [org.lds.stack.petstore.model.Country#38]
10:44:18,500 DEBUG DefaultLoadEventListener: attempting to resolve: [org.lds.stack.petstore.model.Country#38]
10:44:18,500 DEBUG DefaultLoadEventListener: resolved object in session cache: [org.lds.stack.petstore.model.Country#38]
10:44:18,500 DEBUG Loader: result set row: 40
10:44:18,500 DEBUG LongType: returning '38' as column: id3_0_
10:44:18,500 DEBUG Loader: result row: EntityKey[org.lds.stack.petstore.model.Country#38]
10:44:18,500 DEBUG LongType: returning '3' as column: ANIMAL1_1_
10:44:18,500 DEBUG Loader: found row of collection: [org.lds.stack.petstore.model.Animal.countries#3]
10:44:18,500 DEBUG CollectionLoadContext: new collection: instantiating
10:44:18,500 DEBUG LongType: returning '38' as column: COUNTRY2_1_
10:44:18,500 DEBUG DefaultLoadEventListener: loading entity: [org.lds.stack.petstore.model.Country#38]
10:44:18,500 DEBUG DefaultLoadEventListener: attempting to resolve: [org.lds.stack.petstore.model.Country#38]
10:44:18,500 DEBUG DefaultLoadEventListener: resolved object in session cache: [org.lds.stack.petstore.model.Country#38]
10:44:18,500 DEBUG Loader: result set row: 41
10:44:18,500 DEBUG LongType: returning '40' as column: id3_0_
10:44:18,500 DEBUG Loader: result row: EntityKey[org.lds.stack.petstore.model.Country#40]
10:44:18,500 DEBUG Loader: Initializing object from ResultSet: [org.lds.stack.petstore.model.Country#40]
10:44:18,500 DEBUG AbstractEntityPersister: Hydrating entity: [org.lds.stack.petstore.model.Country#40]
10:44:18,500 DEBUG StringType: returning 'Cayman Islands' as column: name3_0_
10:44:18,500 DEBUG LongType: returning '18' as column: ANIMAL1_1_
10:44:18,500 DEBUG Loader: found row of collection: [org.lds.stack.petstore.model.Animal.countries#18]
10:44:18,500 DEBUG CollectionLoadContext: reading row
10:44:18,500 DEBUG LongType: returning '40' as column: COUNTRY2_1_
10:44:18,500 DEBUG DefaultLoadEventListener: loading entity: [org.lds.stack.petstore.model.Country#40]
10:44:18,500 DEBUG DefaultLoadEventListener: attempting to resolve: [org.lds.stack.petstore.model.Country#40]
10:44:18,500 DEBUG DefaultLoadEventListener: resolved object in session cache: [org.lds.stack.petstore.model.Country#40]
10:44:18,500 DEBUG Loader: result set row: 42
10:44:18,500 DEBUG LongType: returning '40' as column: id3_0_
10:44:18,500 DEBUG Loader: result row: EntityKey[org.lds.stack.petstore.model.Country#40]
10:44:18,500 DEBUG LongType: returning '20' as column: ANIMAL1_1_
10:44:18,500 DEBUG Loader: found row of collection: [org.lds.stack.petstore.model.Animal.countries#20]
10:44:18,500 DEBUG CollectionLoadContext: reading row
10:44:18,500 DEBUG LongType: returning '40' as column: COUNTRY2_1_
10:44:18,500 DEBUG DefaultLoadEventListener: loading entity: [org.lds.stack.petstore.model.Country#40]
10:44:18,500 DEBUG DefaultLoadEventListener: attempting to resolve: [org.lds.stack.petstore.model.Country#40]
10:44:18,500 DEBUG DefaultLoadEventListener: resolved object in session cache: [org.lds.stack.petstore.model.Country#40]
10:44:18,500 DEBUG Loader: result set row: 43
10:44:18,500 DEBUG LongType: returning '40' as column: id3_0_
10:44:18,500 DEBUG Loader: result row: EntityKey[org.lds.stack.petstore.model.Country#40]
10:44:18,500 DEBUG LongType: returning '23' as column: ANIMAL1_1_
10:44:18,500 DEBUG Loader: found row of collection: [org.lds.stack.petstore.model.Animal.countries#23]
10:44:18,500 DEBUG CollectionLoadContext: reading row
10:44:18,500 DEBUG LongType: returning '40' as column: COUNTRY2_1_
10:44:18,500 DEBUG DefaultLoadEventListener: loading entity: [org.lds.stack.petstore.model.Country#40]
10:44:18,500 DEBUG DefaultLoadEventListener: attempting to resolve: [org.lds.stack.petstore.model.Country#40]
10:44:18,500 DEBUG DefaultLoadEventListener: resolved object in session cache: [org.lds.stack.petstore.model.Country#40]
10:44:18,500 DEBUG Loader: result set row: 44
10:44:18,500 DEBUG LongType: returning '40' as column: id3_0_
10:44:18,500 DEBUG Loader: result row: EntityKey[org.lds.stack.petstore.model.Country#40]
10:44:18,500 DEBUG LongType: returning '19' as column: ANIMAL1_1_
10:44:18,500 DEBUG Loader: found row of collection: [org.lds.stack.petstore.model.Animal.countries#19]
10:44:18,500 DEBUG CollectionLoadContext: reading row
10:44:18,500 DEBUG LongType: returning '40' as column: COUNTRY2_1_
10:44:18,500 DEBUG DefaultLoadEventListener: loading entity: [org.lds.stack.petstore.model.Country#40]
10:44:18,500 DEBUG DefaultLoadEventListener: attempting to resolve: [org.lds.stack.petstore.model.Country#40]
10:44:18,500 DEBUG DefaultLoadEventListener: resolved object in session cache: [org.lds.stack.petstore.model.Country#40]
10:44:18,500 DEBUG Loader: result set row: 45
10:44:18,500 DEBUG LongType: returning '41' as column: id3_0_
10:44:18,500 DEBUG Loader: result row: EntityKey[org.lds.stack.petstore.model.Country#41]
10:44:18,500 DEBUG Loader: Initializing object from ResultSet: [org.lds.stack.petstore.model.Country#41]
10:44:18,500 DEBUG AbstractEntityPersister: Hydrating entity: [org.lds.stack.petstore.model.Country#41]
10:44:18,500 DEBUG StringType: returning 'Central African Republic' as column: name3_0_
10:44:18,500 DEBUG LongType: returning '22' as column: ANIMAL1_1_
10:44:18,500 DEBUG Loader: found row of collection: [org.lds.stack.petstore.model.Animal.countries#22]
10:44:18,500 DEBUG CollectionLoadContext: new collection: instantiating
10:44:18,500 DEBUG LongType: returning '41' as column: COUNTRY2_1_
10:44:18,500 DEBUG DefaultLoadEventListener: loading entity: [org.lds.stack.petstore.model.Country#41]
10:44:18,500 DEBUG DefaultLoadEventListener: attempting to resolve: [org.lds.stack.petstore.model.Country#41]
10:44:18,500 DEBUG DefaultLoadEventListener: resolved object in session cache: [org.lds.stack.petstore.model.Country#41]
10:44:18,500 DEBUG Loader: result set row: 46
10:44:18,500 DEBUG LongType: returning '44' as column: id3_0_
10:44:18,500 DEBUG Loader: result row: EntityKey[org.lds.stack.petstore.model.Country#44]
10:44:18,500 DEBUG Loader: Initializing object from ResultSet: [org.lds.stack.petstore.model.Country#44]
10:44:18,500 DEBUG AbstractEntityPersister: Hydrating entity: [org.lds.stack.petstore.model.Country#44]
10:44:18,500 DEBUG StringType: returning 'China' as column: name3_0_
10:44:18,500 DEBUG LongType: returning '36' as column: ANIMAL1_1_
10:44:18,500 DEBUG Loader: found row of collection: [org.lds.stack.petstore.model.Animal.countries#36]
10:44:18,500 DEBUG CollectionLoadContext: new collection: instantiating
10:44:18,500 DEBUG LongType: returning '44' as column: COUNTRY2_1_
10:44:18,500 DEBUG DefaultLoadEventListener: loading entity: [org.lds.stack.petstore.model.Country#44]
10:44:18,500 DEBUG DefaultLoadEventListener: attempting to resolve: [org.lds.stack.petstore.model.Country#44]
10:44:18,500 DEBUG DefaultLoadEventListener: resolved object in session cache: [org.lds.stack.petstore.model.Country#44]
10:44:18,500 DEBUG Loader: result set row: 47
10:44:18,500 DEBUG LongType: returning '44' as column: id3_0_
10:44:18,500 DEBUG Loader: result row: EntityKey[org.lds.stack.petstore.model.Country#44]
10:44:18,500 DEBUG LongType: returning '39' as column: ANIMAL1_1_
10:44:18,500 DEBUG Loader: found row of collection: [org.lds.stack.petstore.model.Animal.countries#39]
10:44:18,500 DEBUG CollectionLoadContext: new collection: instantiating
10:44:18,500 DEBUG LongType: returning '44' as column: COUNTRY2_1_
10:44:18,500 DEBUG DefaultLoadEventListener: loading entity: [org.lds.stack.petstore.model.Country#44]
10:44:18,500 DEBUG DefaultLoadEventListener: attempting to resolve: [org.lds.stack.petstore.model.Country#44]
10:44:18,500 DEBUG DefaultLoadEventListener: resolved object in session cache: [org.lds.stack.petstore.model.Country#44]
10:44:18,500 DEBUG Loader: result set row: 48
10:44:18,500 DEBUG LongType: returning '45' as column: id3_0_
10:44:18,500 DEBUG Loader: result row: EntityKey[org.lds.stack.petstore.model.Country#45]
10:44:18,500 DEBUG Loader: Initializing object from ResultSet: [org.lds.stack.petstore.model.Country#45]
10:44:18,500 DEBUG AbstractEntityPersister: Hydrating entity: [org.lds.stack.petstore.model.Country#45]
10:44:18,500 DEBUG StringType: returning 'Christmas Island' as column: name3_0_
10:44:18,500 DEBUG LongType: returning '21' as column: ANIMAL1_1_
10:44:18,500 DEBUG Loader: found row of collection: [org.lds.stack.petstore.model.Animal.countries#21]
10:44:18,500 DEBUG CollectionLoadContext: reading row
10:44:18,500 DEBUG LongType: returning '45' as column: COUNTRY2_1_
10:44:18,500 DEBUG DefaultLoadEventListener: loading entity: [org.lds.stack.petstore.model.Country#45]
10:44:18,500 DEBUG DefaultLoadEventListener: attempting to resolve: [org.lds.stack.petstore.model.Country#45]
10:44:18,500 DEBUG DefaultLoadEventListener: resolved object in session cache: [org.lds.stack.petstore.model.Country#45]
10:44:18,500 DEBUG Loader: result set row: 49
10:44:18,500 DEBUG LongType: returning '46' as column: id3_0_
10:44:18,500 DEBUG Loader: result row: EntityKey[org.lds.stack.petstore.model.Country#46]
10:44:18,500 DEBUG Loader: Initializing object from ResultSet: [org.lds.stack.petstore.model.Country#46]
10:44:18,500 DEBUG AbstractEntityPersister: Hydrating entity: [org.lds.stack.petstore.model.Country#46]
10:44:18,500 DEBUG StringType: returning 'Cocos (Keeling); Islands' as column: name3_0_
10:44:18,500 DEBUG LongType: returning '38' as column: ANIMAL1_1_
10:44:18,500 DEBUG Loader: found row of collection: [org.lds.stack.petstore.model.Animal.countries#38]
10:44:18,500 DEBUG CollectionLoadContext: new collection: instantiating
10:44:18,500 DEBUG LongType: returning '46' as column: COUNTRY2_1_
10:44:18,500 DEBUG DefaultLoadEventListener: loading entity: [org.lds.stack.petstore.model.Country#46]
10:44:18,500 DEBUG DefaultLoadEventListener: attempting to resolve: [org.lds.stack.petstore.model.Country#46]
10:44:18,500 DEBUG DefaultLoadEventListener: resolved object in session cache: [org.lds.stack.petstore.model.Country#46]
10:44:18,515 DEBUG Loader: result set row: 50
10:44:18,515 DEBUG LongType: returning '47' as column: id3_0_
10:44:18,515 DEBUG Loader: result row: EntityKey[org.lds.stack.petstore.model.Country#47]
10:44:18,515 DEBUG Loader: Initializing object from ResultSet: [org.lds.stack.petstore.model.Country#47]
10:44:18,515 DEBUG AbstractEntityPersister: Hydrating entity: [org.lds.stack.petstore.model.Country#47]
10:44:18,515 DEBUG StringType: returning 'Colombia' as column: name3_0_
10:44:18,515 DEBUG LongType: returning '38' as column: ANIMAL1_1_
10:44:18,515 DEBUG Loader: found row of collection: [org.lds.stack.petstore.model.Animal.countries#38]
10:44:18,515 DEBUG CollectionLoadContext: reading row
10:44:18,515 DEBUG LongType: returning '47' as column: COUNTRY2_1_
10:44:18,515 DEBUG DefaultLoadEventListener: loading entity: [org.lds.stack.petstore.model.Country#47]
10:44:18,515 DEBUG DefaultLoadEventListener: attempting to resolve: [org.lds.stack.petstore.model.Country#47]
10:44:18,515 DEBUG DefaultLoadEventListener: resolved object in session cache: [org.lds.stack.petstore.model.Country#47]
10:44:18,515 DEBUG Loader: result set row: 51
10:44:18,515 DEBUG LongType: returning '60' as column: id3_0_
10:44:18,515 DEBUG Loader: result row: EntityKey[org.lds.stack.petstore.model.Country#60]
10:44:18,515 DEBUG Loader: Initializing object from ResultSet: [org.lds.stack.petstore.model.Country#60]
10:44:18,515 DEBUG AbstractEntityPersister: Hydrating entity: [org.lds.stack.petstore.model.Country#60]
10:44:18,515 DEBUG StringType: returning 'Dominica' as column: name3_0_
10:44:18,515 DEBUG LongType: returning '35' as column: ANIMAL1_1_
10:44:18,515 DEBUG Loader: found row of collection: [org.lds.stack.petstore.model.Animal.countries#35]
10:44:18,515 DEBUG CollectionLoadContext: new collection: instantiating
10:44:18,515 DEBUG LongType: returning '60' as column: COUNTRY2_1_
10:44:18,515 DEBUG DefaultLoadEventListener: loading entity: [org.lds.stack.petstore.model.Country#60]
10:44:18,515 DEBUG DefaultLoadEventListener: attempting to resolve: [org.lds.stack.petstore.model.Country#60]
10:44:18,515 DEBUG DefaultLoadEventListener: resolved object in session cache: [org.lds.stack.petstore.model.Country#60]
10:44:18,515 DEBUG Loader: result set row: 52
10:44:18,515 DEBUG LongType: returning '63' as column: id3_0_
10:44:18,515 DEBUG Loader: result row: EntityKey[org.lds.stack.petstore.model.Country#63]
10:44:18,515 DEBUG Loader: Initializing object from ResultSet: [org.lds.stack.petstore.model.Country#63]
10:44:18,515 DEBUG AbstractEntityPersister: Hydrating entity: [org.lds.stack.petstore.model.Country#63]
10:44:18,515 DEBUG StringType: returning 'Ecuador' as column: name3_0_
10:44:18,515 DEBUG LongType: returning '44' as column: ANIMAL1_1_
10:44:18,515 DEBUG Loader: found row of collection: [org.lds.stack.petstore.model.Animal.countries#44]
10:44:18,515 DEBUG CollectionLoadContext: new collection: instantiating
10:44:18,515 DEBUG LongType: returning '63' as column: COUNTRY2_1_
10:44:18,515 DEBUG DefaultLoadEventListener: loading entity: [org.lds.stack.petstore.model.Country#63]
10:44:18,515 DEBUG DefaultLoadEventListener: attempting to resolve: [org.lds.stack.petstore.model.Country#63]
10:44:18,515 DEBUG DefaultLoadEventListener: resolved object in session cache: [org.lds.stack.petstore.model.Country#63]
10:44:18,515 DEBUG Loader: result set row: 53
10:44:18,515 DEBUG LongType: returning '67' as column: id3_0_
10:44:18,515 DEBUG Loader: result row: EntityKey[org.lds.stack.petstore.model.Country#67]
10:44:18,515 DEBUG Loader: Initializing object from ResultSet: [org.lds.stack.petstore.model.Country#67]
10:44:18,515 DEBUG AbstractEntityPersister: Hydrating entity: [org.lds.stack.petstore.model.Country#67]
10:44:18,515 DEBUG StringType: returning 'Eritrea' as column: name3_0_
10:44:18,515 DEBUG LongType: returning '51' as column: ANIMAL1_1_
10:44:18,515 DEBUG Loader: found row of collection: [org.lds.stack.petstore.model.Animal.countries#51]
10:44:18,515 DEBUG CollectionLoadContext: new collection: instantiating
10:44:18,515 DEBUG LongType: returning '67' as column: COUNTRY2_1_
10:44:18,515 DEBUG DefaultLoadEventListener: loading entity: [org.lds.stack.petstore.model.Country#67]
10:44:18,515 DEBUG DefaultLoadEventListener: attempting to resolve: [org.lds.stack.petstore.model.Country#67]
10:44:18,515 DEBUG DefaultLoadEventListener: resolved object in session cache: [org.lds.stack.petstore.model.Country#67]
10:44:18,515 DEBUG Loader: result set row: 54
10:44:18,515 DEBUG LongType: returning '77' as column: id3_0_
10:44:18,515 DEBUG Loader: result row: EntityKey[org.lds.stack.petstore.model.Country#77]
10:44:18,515 DEBUG Loader: Initializing object from ResultSet: [org.lds.stack.petstore.model.Country#77]
10:44:18,515 DEBUG AbstractEntityPersister: Hydrating entity: [org.lds.stack.petstore.model.Country#77]
10:44:18,515 DEBUG StringType: returning 'French Southern Territories' as column: name3_0_
10:44:18,515 DEBUG LongType: returning '40' as column: ANIMAL1_1_
10:44:18,515 DEBUG Loader: found row of collection: [org.lds.stack.petstore.model.Animal.countries#40]
10:44:18,515 DEBUG CollectionLoadContext: new collection: instantiating
10:44:18,515 DEBUG LongType: returning '77' as column: COUNTRY2_1_
10:44:18,515 DEBUG DefaultLoadEventListener: loading entity: [org.lds.stack.petstore.model.Country#77]
10:44:18,515 DEBUG DefaultLoadEventListener: attempting to resolve: [org.lds.stack.petstore.model.Country#77]
10:44:18,515 DEBUG DefaultLoadEventListener: resolved object in session cache: [org.lds.stack.petstore.model.Country#77]
10:44:18,515 DEBUG Loader: result set row: 55
10:44:18,515 DEBUG LongType: returning '88' as column: id3_0_
10:44:18,515 DEBUG Loader: result row: EntityKey[org.lds.stack.petstore.model.Country#88]
10:44:18,515 DEBUG Loader: Initializing object from ResultSet: [org.lds.stack.petstore.model.Country#88]
10:44:18,515 DEBUG AbstractEntityPersister: Hydrating entity: [org.lds.stack.petstore.model.Country#88]
10:44:18,515 DEBUG StringType: returning 'Guam' as column: name3_0_
10:44:18,515 DEBUG LongType: returning '22' as column: ANIMAL1_1_
10:44:18,515 DEBUG Loader: found row of collection: [org.lds.stack.petstore.model.Animal.countries#22]
10:44:18,515 DEBUG CollectionLoadContext: reading row
10:44:18,515 DEBUG LongType: returning '88' as column: COUNTRY2_1_
10:44:18,515 DEBUG DefaultLoadEventListener: loading entity: [org.lds.stack.petstore.model.Country#88]
10:44:18,515 DEBUG DefaultLoadEventListener: attempting to resolve: [org.lds.stack.petstore.model.Country#88]
10:44:18,515 DEBUG DefaultLoadEventListener: resolved object in session cache: [org.lds.stack.petstore.model.Country#88]
10:44:18,515 DEBUG Loader: result set row: 56
10:44:18,515 DEBUG LongType: returning '88' as column: id3_0_
10:44:18,515 DEBUG Loader: result row: EntityKey[org.lds.stack.petstore.model.Country#88]
10:44:18,515 DEBUG LongType: returning '37' as column: ANIMAL1_1_
10:44:18,515 DEBUG Loader: found row of collection: [org.lds.stack.petstore.model.Animal.countries#37]
10:44:18,515 DEBUG CollectionLoadContext: new collection: instantiating
10:44:18,515 DEBUG LongType: returning '88' as column: COUNTRY2_1_
10:44:18,515 DEBUG DefaultLoadEventListener: loading entity: [org.lds.stack.petstore.model.Country#88]
10:44:18,515 DEBUG DefaultLoadEventListener: attempting to resolve: [org.lds.stack.petstore.model.Country#88]
10:44:18,515 DEBUG DefaultLoadEventListener: resolved object in session cache: [org.lds.stack.petstore.model.Country#88]
10:44:18,515 DEBUG Loader: result set row: 57
10:44:18,515 DEBUG LongType: returning '90' as column: id3_0_
10:44:18,515 DEBUG Loader: result row: EntityKey[org.lds.stack.petstore.model.Country#90]
10:44:18,515 DEBUG Loader: Initializing object from ResultSet: [org.lds.stack.petstore.model.Country#90]
10:44:18,515 DEBUG AbstractEntityPersister: Hydrating entity: [org.lds.stack.petstore.model.Country#90]
10:44:18,515 DEBUG StringType: returning 'Guinea' as column: name3_0_
10:44:18,515 DEBUG LongType: returning '23' as column: ANIMAL1_1_
10:44:18,515 DEBUG Loader: found row of collection: [org.lds.stack.petstore.model.Animal.countries#23]
10:44:18,515 DEBUG CollectionLoadContext: reading row
10:44:18,515 DEBUG LongType: returning '90' as column: COUNTRY2_1_
10:44:18,515 DEBUG DefaultLoadEventListener: loading entity: [org.lds.stack.petstore.model.Country#90]
10:44:18,515 DEBUG DefaultLoadEventListener: attempting to resolve: [org.lds.stack.petstore.model.Country#90]
10:44:18,515 DEBUG DefaultLoadEventListener: resolved object in session cache: [org.lds.stack.petstore.model.Country#90]
10:44:18,515 DEBUG Loader: result set row: 58
10:44:18,515 DEBUG LongType: returning '90' as column: id3_0_
10:44:18,515 DEBUG Loader: result row: EntityKey[org.lds.stack.petstore.model.Country#90]
10:44:18,515 DEBUG LongType: returning '41' as column: ANIMAL1_1_
10:44:18,515 DEBUG Loader: found row of collection: [org.lds.stack.petstore.model.Animal.countries#41]
10:44:18,515 DEBUG CollectionLoadContext: new collection: instantiating
10:44:18,515 DEBUG LongType: returning '90' as column: COUNTRY2_1_
10:44:18,515 DEBUG DefaultLoadEventListener: loading entity: [org.lds.stack.petstore.model.Country#90]
10:44:18,515 DEBUG DefaultLoadEventListener: attempting to resolve: [org.lds.stack.petstore.model.Country#90]
10:44:18,515 DEBUG DefaultLoadEventListener: resolved object in session cache: [org.lds.stack.petstore.model.Country#90]
10:44:18,515 DEBUG Loader: result set row: 59
10:44:18,515 DEBUG LongType: returning '91' as column: id3_0_
10:44:18,515 DEBUG Loader: result row: EntityKey[org.lds.stack.petstore.model.Country#91]
10:44:18,515 DEBUG Loader: Initializing object from ResultSet: [org.lds.stack.petstore.model.Country#91]
10:44:18,515 DEBUG AbstractEntityPersister: Hydrating entity: [org.lds.stack.petstore.model.Country#91]
10:44:18,515 DEBUG StringType: returning 'Guinea-Bissau' as column: name3_0_
10:44:18,515 DEBUG LongType: returning '42' as column: ANIMAL1_1_
10:44:18,515 DEBUG Loader: found row of collection: [org.lds.stack.petstore.model.Animal.countries#42]
10:44:18,515 DEBUG CollectionLoadContext: new collection: instantiating
10:44:18,515 DEBUG LongType: returning '91' as column: COUNTRY2_1_
10:44:18,515 DEBUG DefaultLoadEventListener: loading entity: [org.lds.stack.petstore.model.Country#91]
10:44:18,515 DEBUG DefaultLoadEventListener: attempting to resolve: [org.lds.stack.petstore.model.Country#91]
10:44:18,515 DEBUG DefaultLoadEventListener: resolved object in session cache: [org.lds.stack.petstore.model.Country#91]
10:44:18,515 DEBUG Loader: result set row: 60
10:44:18,515 DEBUG LongType: returning '98' as column: id3_0_
10:44:18,515 DEBUG Loader: result row: EntityKey[org.lds.stack.petstore.model.Country#98]
10:44:18,515 DEBUG Loader: Initializing object from ResultSet: [org.lds.stack.petstore.model.Country#98]
10:44:18,515 DEBUG AbstractEntityPersister: Hydrating entity: [org.lds.stack.petstore.model.Country#98]
10:44:18,515 DEBUG StringType: returning 'Hungary' as column: name3_0_
10:44:18,515 DEBUG LongType: returning '47' as column: ANIMAL1_1_
10:44:18,515 DEBUG Loader: found row of collection: [org.lds.stack.petstore.model.Animal.countries#47]
10:44:18,515 DEBUG CollectionLoadContext: reading row
10:44:18,515 DEBUG LongType: returning '98' as column: COUNTRY2_1_
10:44:18,515 DEBUG DefaultLoadEventListener: loading entity: [org.lds.stack.petstore.model.Country#98]
10:44:18,515 DEBUG DefaultLoadEventListener: attempting to resolve: [org.lds.stack.petstore.model.Country#98]
10:44:18,515 DEBUG DefaultLoadEventListener: resolved object in session cache: [org.lds.stack.petstore.model.Country#98]
10:44:18,515 DEBUG Loader: result set row: 61
10:44:18,515 DEBUG LongType: returning '99' as column: id3_0_
10:44:18,515 DEBUG Loader: result row: EntityKey[org.lds.stack.petstore.model.Country#99]
10:44:18,515 DEBUG Loader: Initializing object from ResultSet: [org.lds.stack.petstore.model.Country#99]
10:44:18,515 DEBUG AbstractEntityPersister: Hydrating entity: [org.lds.stack.petstore.model.Country#99]
10:44:18,515 DEBUG StringType: returning 'Iceland' as column: name3_0_
10:44:18,515 DEBUG LongType: returning '33' as column: ANIMAL1_1_
10:44:18,515 DEBUG Loader: found row of collection: [org.lds.stack.petstore.model.Animal.countries#33]
10:44:18,515 DEBUG CollectionLoadContext: new collection: instantiating
10:44:18,515 DEBUG LongType: returning '99' as column: COUNTRY2_1_
10:44:18,515 DEBUG DefaultLoadEventListener: loading entity: [org.lds.stack.petstore.model.Country#99]
10:44:18,515 DEBUG DefaultLoadEventListener: attempting to resolve: [org.lds.stack.petstore.model.Country#99]
10:44:18,515 DEBUG DefaultLoadEventListener: resolved object in session cache: [org.lds.stack.petstore.model.Country#99]
10:44:18,515 DEBUG Loader: result set row: 62
10:44:18,515 DEBUG LongType: returning '100' as column: id3_0_
10:44:18,515 DEBUG Loader: result row: EntityKey[org.lds.stack.petstore.model.Country#100]
10:44:18,515 DEBUG Loader: Initializing object from ResultSet: [org.lds.stack.petstore.model.Country#100]
10:44:18,515 DEBUG AbstractEntityPersister: Hydrating entity: [org.lds.stack.petstore.model.Country#100]
10:44:18,515 DEBUG StringType: returning 'India' as column: name3_0_
10:44:18,515 DEBUG LongType: returning '24' as column: ANIMAL1_1_
10:44:18,515 DEBUG Loader: found row of collection: [org.lds.stack.petstore.model.Animal.countries#24]
10:44:18,515 DEBUG CollectionLoadContext: reading row
10:44:18,515 DEBUG LongType: returning '100' as column: COUNTRY2_1_
10:44:18,515 DEBUG DefaultLoadEventListener: loading entity: [org.lds.stack.petstore.model.Country#100]
10:44:18,515 DEBUG DefaultLoadEventListener: attempting to resolve: [org.lds.stack.petstore.model.Country#100]
10:44:18,515 DEBUG DefaultLoadEventListener: resolved object in session cache: [org.lds.stack.petstore.model.Country#100]
10:44:18,515 DEBUG Loader: result set row: 63
10:44:18,515 DEBUG LongType: returning '139' as column: id3_0_
10:44:18,515 DEBUG Loader: result row: EntityKey[org.lds.stack.petstore.model.Country#139]
10:44:18,515 DEBUG Loader: Initializing object from ResultSet: [org.lds.stack.petstore.model.Country#139]
10:44:18,515 DEBUG AbstractEntityPersister: Hydrating entity: [org.lds.stack.petstore.model.Country#139]
10:44:18,515 DEBUG StringType: returning 'Mexico' as column: name3_0_
10:44:18,515 DEBUG LongType: returning '1' as column: ANIMAL1_1_
10:44:18,515 DEBUG Loader: found row of collection: [org.lds.stack.petstore.model.Animal.countries#1]
10:44:18,515 DEBUG CollectionLoadContext: reading row
10:44:18,515 DEBUG LongType: returning '139' as column: COUNTRY2_1_
10:44:18,515 DEBUG DefaultLoadEventListener: loading entity: [org.lds.stack.petstore.model.Country#139]
10:44:18,515 DEBUG DefaultLoadEventListener: attempting to resolve: [org.lds.stack.petstore.model.Country#139]
10:44:18,515 DEBUG DefaultLoadEventListener: resolved object in session cache: [org.lds.stack.petstore.model.Country#139]
10:44:18,515 DEBUG Loader: result set row: 64
10:44:18,515 DEBUG LongType: returning '139' as column: id3_0_
10:44:18,515 DEBUG Loader: result row: EntityKey[org.lds.stack.petstore.model.Country#139]
10:44:18,515 DEBUG LongType: returning '16' as column: ANIMAL1_1_
10:44:18,515 DEBUG Loader: found row of collection: [org.lds.stack.petstore.model.Animal.countries#16]
10:44:18,515 DEBUG CollectionLoadContext: reading row
10:44:18,515 DEBUG LongType: returning '139' as column: COUNTRY2_1_
10:44:18,515 DEBUG DefaultLoadEventListener: loading entity: [org.lds.stack.petstore.model.Country#139]
10:44:18,515 DEBUG DefaultLoadEventListener: attempting to resolve: [org.lds.stack.petstore.model.Country#139]
10:44:18,515 DEBUG DefaultLoadEventListener: resolved object in session cache: [org.lds.stack.petstore.model.Country#139]
10:44:18,515 DEBUG Loader: result set row: 65
10:44:18,515 DEBUG LongType: returning '139' as column: id3_0_
10:44:18,515 DEBUG Loader: result row: EntityKey[org.lds.stack.petstore.model.Country#139]
10:44:18,515 DEBUG LongType: returning '15' as column: ANIMAL1_1_
10:44:18,515 DEBUG Loader: found row of collection: [org.lds.stack.petstore.model.Animal.countries#15]
10:44:18,515 DEBUG CollectionLoadContext: reading row
10:44:18,515 DEBUG LongType: returning '139' as column: COUNTRY2_1_
10:44:18,515 DEBUG DefaultLoadEventListener: loading entity: [org.lds.stack.petstore.model.Country#139]
10:44:18,515 DEBUG DefaultLoadEventListener: attempting to resolve: [org.lds.stack.petstore.model.Country#139]
10:44:18,515 DEBUG DefaultLoadEventListener: resolved object in session cache: [org.lds.stack.petstore.model.Country#139]
10:44:18,515 DEBUG Loader: result set row: 66
10:44:18,515 DEBUG LongType: returning '139' as column: id3_0_
10:44:18,515 DEBUG Loader: result row: EntityKey[org.lds.stack.petstore.model.Country#139]
10:44:18,515 DEBUG LongType: returning '14' as column: ANIMAL1_1_
10:44:18,515 DEBUG Loader: found row of collection: [org.lds.stack.petstore.model.Animal.countries#14]
10:44:18,515 DEBUG CollectionLoadContext: reading row
10:44:18,515 DEBUG LongType: returning '139' as column: COUNTRY2_1_
10:44:18,515 DEBUG DefaultLoadEventListener: loading entity: [org.lds.stack.petstore.model.Country#139]
10:44:18,515 DEBUG DefaultLoadEventListener: attempting to resolve: [org.lds.stack.petstore.model.Country#139]
10:44:18,515 DEBUG DefaultLoadEventListener: resolved object in session cache: [org.lds.stack.petstore.model.Country#139]
10:44:18,515 DEBUG Loader: result set row: 67
10:44:18,515 DEBUG LongType: returning '139' as column: id3_0_
10:44:18,515 DEBUG Loader: result row: EntityKey[org.lds.stack.petstore.model.Country#139]
10:44:18,515 DEBUG LongType: returning '13' as column: ANIMAL1_1_
10:44:18,515 DEBUG Loader: found row of collection: [org.lds.stack.petstore.model.Animal.countries#13]
10:44:18,515 DEBUG CollectionLoadContext: reading row
10:44:18,515 DEBUG LongType: returning '139' as column: COUNTRY2_1_
10:44:18,515 DEBUG DefaultLoadEventListener: loading entity: [org.lds.stack.petstore.model.Country#139]
10:44:18,515 DEBUG DefaultLoadEventListener: attempting to resolve: [org.lds.stack.petstore.model.Country#139]
10:44:18,515 DEBUG DefaultLoadEventListener: resolved object in session cache: [org.lds.stack.petstore.model.Country#139]
10:44:18,515 DEBUG Loader: result set row: 68
10:44:18,515 DEBUG LongType: returning '139' as column: id3_0_
10:44:18,515 DEBUG Loader: result row: EntityKey[org.lds.stack.petstore.model.Country#139]
10:44:18,515 DEBUG LongType: returning '12' as column: ANIMAL1_1_
10:44:18,515 DEBUG Loader: found row of collection: [org.lds.stack.petstore.model.Animal.countries#12]
10:44:18,515 DEBUG CollectionLoadContext: reading row
10:44:18,515 DEBUG LongType: returning '139' as column: COUNTRY2_1_
10:44:18,515 DEBUG DefaultLoadEventListener: loading entity: [org.lds.stack.petstore.model.Country#139]
10:44:18,515 DEBUG DefaultLoadEventListener: attempting to resolve: [org.lds.stack.petstore.model.Country#139]
10:44:18,515 DEBUG DefaultLoadEventListener: resolved object in session cache: [org.lds.stack.petstore.model.Country#139]
10:44:18,515 DEBUG Loader: result set row: 69
10:44:18,515 DEBUG LongType: returning '139' as column: id3_0_
10:44:18,515 DEBUG Loader: result row: EntityKey[org.lds.stack.petstore.model.Country#139]
10:44:18,515 DEBUG LongType: returning '11' as column: ANIMAL1_1_
10:44:18,515 DEBUG Loader: found row of collection: [org.lds.stack.petstore.model.Animal.countries#11]
10:44:18,515 DEBUG CollectionLoadContext: reading row
10:44:18,515 DEBUG LongType: returning '139' as column: COUNTRY2_1_
10:44:18,515 DEBUG DefaultLoadEventListener: loading entity: [org.lds.stack.petstore.model.Country#139]
10:44:18,515 DEBUG DefaultLoadEventListener: attempting to resolve: [org.lds.stack.petstore.model.Country#139]
10:44:18,515 DEBUG DefaultLoadEventListener: resolved object in session cache: [org.lds.stack.petstore.model.Country#139]
10:44:18,515 DEBUG Loader: result set row: 70
10:44:18,515 DEBUG LongType: returning '139' as column: id3_0_
10:44:18,515 DEBUG Loader: result row: EntityKey[org.lds.stack.petstore.model.Country#139]
10:44:18,515 DEBUG LongType: returning '10' as column: ANIMAL1_1_
10:44:18,515 DEBUG Loader: found row of collection: [org.lds.stack.petstore.model.Animal.countries#10]
10:44:18,515 DEBUG CollectionLoadContext: reading row
10:44:18,515 DEBUG LongType: returning '139' as column: COUNTRY2_1_
10:44:18,515 DEBUG DefaultLoadEventListener: loading entity: [org.lds.stack.petstore.model.Country#139]
10:44:18,515 DEBUG DefaultLoadEventListener: attempting to resolve: [org.lds.stack.petstore.model.Country#139]
10:44:18,515 DEBUG DefaultLoadEventListener: resolved object in session cache: [org.lds.stack.petstore.model.Country#139]
10:44:18,515 DEBUG Loader: result set row: 71
10:44:18,515 DEBUG LongType: returning '139' as column: id3_0_
10:44:18,515 DEBUG Loader: result row: EntityKey[org.lds.stack.petstore.model.Country#139]
10:44:18,515 DEBUG LongType: returning '9' as column: ANIMAL1_1_
10:44:18,515 DEBUG Loader: found row of collection: [org.lds.stack.petstore.model.Animal.countries#9]
10:44:18,515 DEBUG CollectionLoadContext: reading row
10:44:18,515 DEBUG LongType: returning '139' as column: COUNTRY2_1_
10:44:18,515 DEBUG DefaultLoadEventListener: loading entity: [org.lds.stack.petstore.model.Country#139]
10:44:18,515 DEBUG DefaultLoadEventListener: attempting to resolve: [org.lds.stack.petstore.model.Country#139]
10:44:18,515 DEBUG DefaultLoadEventListener: resolved object in session cache: [org.lds.stack.petstore.model.Country#139]
10:44:18,515 DEBUG Loader: result set row: 72
10:44:18,515 DEBUG LongType: returning '139' as column: id3_0_
10:44:18,515 DEBUG Loader: result row: EntityKey[org.lds.stack.petstore.model.Country#139]
10:44:18,515 DEBUG LongType: returning '8' as column: ANIMAL1_1_
10:44:18,515 DEBUG Loader: found row of collection: [org.lds.stack.petstore.model.Animal.countries#8]
10:44:18,515 DEBUG CollectionLoadContext: reading row
10:44:18,515 DEBUG LongType: returning '139' as column: COUNTRY2_1_
10:44:18,515 DEBUG DefaultLoadEventListener: loading entity: [org.lds.stack.petstore.model.Country#139]
10:44:18,515 DEBUG DefaultLoadEventListener: attempting to resolve: [org.lds.stack.petstore.model.Country#139]
10:44:18,515 DEBUG DefaultLoadEventListener: resolved object in session cache: [org.lds.stack.petstore.model.Country#139]
10:44:18,515 DEBUG Loader: result set row: 73
10:44:18,515 DEBUG LongType: returning '139' as column: id3_0_
10:44:18,515 DEBUG Loader: result row: EntityKey[org.lds.stack.petstore.model.Country#139]
10:44:18,515 DEBUG LongType: returning '7' as column: ANIMAL1_1_
10:44:18,515 DEBUG Loader: found row of collection: [org.lds.stack.petstore.model.Animal.countries#7]
10:44:18,515 DEBUG CollectionLoadContext: reading row
10:44:18,515 DEBUG LongType: returning '139' as column: COUNTRY2_1_
10:44:18,515 DEBUG DefaultLoadEventListener: loading entity: [org.lds.stack.petstore.model.Country#139]
10:44:18,515 DEBUG DefaultLoadEventListener: attempting to resolve: [org.lds.stack.petstore.model.Country#139]
10:44:18,515 DEBUG DefaultLoadEventListener: resolved object in session cache: [org.lds.stack.petstore.model.Country#139]
10:44:18,515 DEBUG Loader: result set row: 74
10:44:18,515 DEBUG LongType: returning '139' as column: id3_0_
10:44:18,515 DEBUG Loader: result row: EntityKey[org.lds.stack.petstore.model.Country#139]
10:44:18,515 DEBUG LongType: returning '6' as column: ANIMAL1_1_
10:44:18,515 DEBUG Loader: found row of collection: [org.lds.stack.petstore.model.Animal.countries#6]
10:44:18,515 DEBUG CollectionLoadContext: reading row
10:44:18,515 DEBUG LongType: returning '139' as column: COUNTRY2_1_
10:44:18,515 DEBUG DefaultLoadEventListener: loading entity: [org.lds.stack.petstore.model.Country#139]
10:44:18,515 DEBUG DefaultLoadEventListener: attempting to resolve: [org.lds.stack.petstore.model.Country#139]
10:44:18,515 DEBUG DefaultLoadEventListener: resolved object in session cache: [org.lds.stack.petstore.model.Country#139]
10:44:18,515 DEBUG Loader: result set row: 75
10:44:18,515 DEBUG LongType: returning '139' as column: id3_0_
10:44:18,515 DEBUG Loader: result row: EntityKey[org.lds.stack.petstore.model.Country#139]
10:44:18,515 DEBUG LongType: returning '5' as column: ANIMAL1_1_
10:44:18,515 DEBUG Loader: found row of collection: [org.lds.stack.petstore.model.Animal.countries#5]
10:44:18,515 DEBUG CollectionLoadContext: reading row
10:44:18,515 DEBUG LongType: returning '139' as column: COUNTRY2_1_
10:44:18,515 DEBUG DefaultLoadEventListener: loading entity: [org.lds.stack.petstore.model.Country#139]
10:44:18,515 DEBUG DefaultLoadEventListener: attempting to resolve: [org.lds.stack.petstore.model.Country#139]
10:44:18,515 DEBUG DefaultLoadEventListener: resolved object in session cache: [org.lds.stack.petstore.model.Country#139]
10:44:18,515 DEBUG Loader: result set row: 76
10:44:18,515 DEBUG LongType: returning '139' as column: id3_0_
10:44:18,515 DEBUG Loader: result row: EntityKey[org.lds.stack.petstore.model.Country#139]
10:44:18,515 DEBUG LongType: returning '4' as column: ANIMAL1_1_
10:44:18,515 DEBUG Loader: found row of collection: [org.lds.stack.petstore.model.Animal.countries#4]
10:44:18,515 DEBUG CollectionLoadContext: reading row
10:44:18,515 DEBUG LongType: returning '139' as column: COUNTRY2_1_
10:44:18,515 DEBUG DefaultLoadEventListener: loading entity: [org.lds.stack.petstore.model.Country#139]
10:44:18,515 DEBUG DefaultLoadEventListener: attempting to resolve: [org.lds.stack.petstore.model.Country#139]
10:44:18,515 DEBUG DefaultLoadEventListener: resolved object in session cache: [org.lds.stack.petstore.model.Country#139]
10:44:18,515 DEBUG Loader: result set row: 77
10:44:18,515 DEBUG LongType: returning '139' as column: id3_0_
10:44:18,515 DEBUG Loader: result row: EntityKey[org.lds.stack.petstore.model.Country#139]
10:44:18,515 DEBUG LongType: returning '3' as column: ANIMAL1_1_
10:44:18,515 DEBUG Loader: found row of collection: [org.lds.stack.petstore.model.Animal.countries#3]
10:44:18,515 DEBUG CollectionLoadContext: reading row
10:44:18,515 DEBUG LongType: returning '139' as column: COUNTRY2_1_
10:44:18,515 DEBUG DefaultLoadEventListener: loading entity: [org.lds.stack.petstore.model.Country#139]
10:44:18,515 DEBUG DefaultLoadEventListener: attempting to resolve: [org.lds.stack.petstore.model.Country#139]
10:44:18,515 DEBUG DefaultLoadEventListener: resolved object in session cache: [org.lds.stack.petstore.model.Country#139]
10:44:18,515 DEBUG Loader: result set row: 78
10:44:18,515 DEBUG LongType: returning '139' as column: id3_0_
10:44:18,515 DEBUG Loader: result row: EntityKey[org.lds.stack.petstore.model.Country#139]
10:44:18,515 DEBUG LongType: returning '2' as column: ANIMAL1_1_
10:44:18,515 DEBUG Loader: found row of collection: [org.lds.stack.petstore.model.Animal.countries#2]
10:44:18,515 DEBUG CollectionLoadContext: reading row
10:44:18,515 DEBUG LongType: returning '139' as column: COUNTRY2_1_
10:44:18,515 DEBUG DefaultLoadEventListener: loading entity: [org.lds.stack.petstore.model.Country#139]
10:44:18,515 DEBUG DefaultLoadEventListener: attempting to resolve: [org.lds.stack.petstore.model.Country#139]
10:44:18,515 DEBUG DefaultLoadEventListener: resolved object in session cache: [org.lds.stack.petstore.model.Country#139]
10:44:18,515 DEBUG Loader: result set row: 79
10:44:18,515 DEBUG LongType: returning '150' as column: id3_0_
10:44:18,515 DEBUG Loader: result row: EntityKey[org.lds.stack.petstore.model.Country#150]
10:44:18,515 DEBUG Loader: Initializing object from ResultSet: [org.lds.stack.petstore.model.Country#150]
10:44:18,515 DEBUG AbstractEntityPersister: Hydrating entity: [org.lds.stack.petstore.model.Country#150]
10:44:18,515 DEBUG StringType: returning 'Nepal' as column: name3_0_
10:44:18,515 DEBUG LongType: returning '22' as column: ANIMAL1_1_
10:44:18,515 DEBUG Loader: found row of collection: [org.lds.stack.petstore.model.Animal.countries#22]
10:44:18,515 DEBUG CollectionLoadContext: reading row
10:44:18,515 DEBUG LongType: returning '150' as column: COUNTRY2_1_
10:44:18,515 DEBUG DefaultLoadEventListener: loading entity: [org.lds.stack.petstore.model.Country#150]
10:44:18,515 DEBUG DefaultLoadEventListener: attempting to resolve: [org.lds.stack.petstore.model.Country#150]
10:44:18,515 DEBUG DefaultLoadEventListener: resolved object in session cache: [org.lds.stack.petstore.model.Country#150]
10:44:18,515 DEBUG Loader: result set row: 80
10:44:18,515 DEBUG LongType: returning '214' as column: id3_0_
10:44:18,515 DEBUG Loader: result row: EntityKey[org.lds.stack.petstore.model.Country#214]
10:44:18,515 DEBUG Loader: Initializing object from ResultSet: [org.lds.stack.petstore.model.Country#214]
10:44:18,515 DEBUG AbstractEntityPersister: Hydrating entity: [org.lds.stack.petstore.model.Country#214]
10:44:18,515 DEBUG StringType: returning 'Tonga' as column: name3_0_
10:44:18,515 DEBUG LongType: returning '21' as column: ANIMAL1_1_
10:44:18,515 DEBUG Loader: found row of collection: [org.lds.stack.petstore.model.Animal.countries#21]
10:44:18,515 DEBUG CollectionLoadContext: reading row
10:44:18,515 DEBUG LongType: returning '214' as column: COUNTRY2_1_
10:44:18,515 DEBUG DefaultLoadEventListener: loading entity: [org.lds.stack.petstore.model.Country#214]
10:44:18,515 DEBUG DefaultLoadEventListener: attempting to resolve: [org.lds.stack.petstore.model.Country#214]
10:44:18,515 DEBUG DefaultLoadEventListener: resolved object in session cache: [org.lds.stack.petstore.model.Country#214]
10:44:18,515 DEBUG Loader: result set row: 81
10:44:18,515 DEBUG LongType: returning '224' as column: id3_0_
10:44:18,531 DEBUG Loader: result row: EntityKey[org.lds.stack.petstore.model.Country#224]
10:44:18,531 DEBUG Loader: Initializing object from ResultSet: [org.lds.stack.petstore.model.Country#224]
10:44:18,531 DEBUG AbstractEntityPersister: Hydrating entity: [org.lds.stack.petstore.model.Country#224]
10:44:18,531 DEBUG StringType: returning 'United Kingdom' as column: name3_0_
10:44:18,531 DEBUG LongType: returning '1' as column: ANIMAL1_1_
10:44:18,531 DEBUG Loader: found row of collection: [org.lds.stack.petstore.model.Animal.countries#1]
10:44:18,546 DEBUG CollectionLoadContext: reading row
10:44:18,546 DEBUG LongType: returning '224' as column: COUNTRY2_1_
10:44:18,546 DEBUG DefaultLoadEventListener: loading entity: [org.lds.stack.petstore.model.Country#224]
10:44:18,546 DEBUG DefaultLoadEventListener: attempting to resolve: [org.lds.stack.petstore.model.Country#224]
10:44:18,546 DEBUG DefaultLoadEventListener: resolved object in session cache: [org.lds.stack.petstore.model.Country#224]
10:44:18,546 DEBUG Loader: result set row: 82
10:44:18,546 DEBUG LongType: returning '224' as column: id3_0_
10:44:18,546 DEBUG Loader: result row: EntityKey[org.lds.stack.petstore.model.Country#224]
10:44:18,546 DEBUG LongType: returning '20' as column: ANIMAL1_1_
10:44:18,546 DEBUG Loader: found row of collection: [org.lds.stack.petstore.model.Animal.countries#20]
10:44:18,546 DEBUG CollectionLoadContext: reading row
10:44:18,546 DEBUG LongType: returning '224' as column: COUNTRY2_1_
10:44:18,546 DEBUG DefaultLoadEventListener: loading entity: [org.lds.stack.petstore.model.Country#224]
10:44:18,546 DEBUG DefaultLoadEventListener: attempting to resolve: [org.lds.stack.petstore.model.Country#224]
10:44:18,546 DEBUG DefaultLoadEventListener: resolved object in session cache: [org.lds.stack.petstore.model.Country#224]
10:44:18,546 DEBUG Loader: result set row: 83
10:44:18,546 DEBUG LongType: returning '224' as column: id3_0_
10:44:18,546 DEBUG Loader: result row: EntityKey[org.lds.stack.petstore.model.Country#224]
10:44:18,546 DEBUG LongType: returning '19' as column: ANIMAL1_1_
10:44:18,546 DEBUG Loader: found row of collection: [org.lds.stack.petstore.model.Animal.countries#19]
10:44:18,546 DEBUG CollectionLoadContext: reading row
10:44:18,546 DEBUG LongType: returning '224' as column: COUNTRY2_1_
10:44:18,546 DEBUG DefaultLoadEventListener: loading entity: [org.lds.stack.petstore.model.Country#224]
10:44:18,546 DEBUG DefaultLoadEventListener: attempting to resolve: [org.lds.stack.petstore.model.Country#224]
10:44:18,546 DEBUG DefaultLoadEventListener: resolved object in session cache: [org.lds.stack.petstore.model.Country#224]
10:44:18,546 DEBUG Loader: result set row: 84
10:44:18,546 DEBUG LongType: returning '224' as column: id3_0_
10:44:18,546 DEBUG Loader: result row: EntityKey[org.lds.stack.petstore.model.Country#224]
10:44:18,546 DEBUG LongType: returning '16' as column: ANIMAL1_1_
10:44:18,546 DEBUG Loader: found row of collection: [org.lds.stack.petstore.model.Animal.countries#16]
10:44:18,546 DEBUG CollectionLoadContext: reading row
10:44:18,546 DEBUG LongType: returning '224' as column: COUNTRY2_1_
10:44:18,546 DEBUG DefaultLoadEventListener: loading entity: [org.lds.stack.petstore.model.Country#224]
10:44:18,546 DEBUG DefaultLoadEventListener: attempting to resolve: [org.lds.stack.petstore.model.Country#224]
10:44:18,546 DEBUG DefaultLoadEventListener: resolved object in session cache: [org.lds.stack.petstore.model.Country#224]
10:44:18,546 DEBUG Loader: result set row: 85
10:44:18,546 DEBUG LongType: returning '224' as column: id3_0_
10:44:18,546 DEBUG Loader: result row: EntityKey[org.lds.stack.petstore.model.Country#224]
10:44:18,546 DEBUG LongType: returning '15' as column: ANIMAL1_1_
10:44:18,546 DEBUG Loader: found row of collection: [org.lds.stack.petstore.model.Animal.countries#15]
10:44:18,546 DEBUG CollectionLoadContext: reading row
10:44:18,546 DEBUG LongType: returning '224' as column: COUNTRY2_1_
10:44:18,546 DEBUG DefaultLoadEventListener: loading entity: [org.lds.stack.petstore.model.Country#224]
10:44:18,546 DEBUG DefaultLoadEventListener: attempting to resolve: [org.lds.stack.petstore.model.Country#224]
10:44:18,546 DEBUG DefaultLoadEventListener: resolved object in session cache: [org.lds.stack.petstore.model.Country#224]
10:44:18,546 DEBUG Loader: result set row: 86
10:44:18,546 DEBUG LongType: returning '224' as column: id3_0_
10:44:18,546 DEBUG Loader: result row: EntityKey[org.lds.stack.petstore.model.Country#224]
10:44:18,546 DEBUG LongType: returning '14' as column: ANIMAL1_1_
10:44:18,546 DEBUG Loader: found row of collection: [org.lds.stack.petstore.model.Animal.countries#14]
10:44:18,546 DEBUG CollectionLoadContext: reading row
10:44:18,546 DEBUG LongType: returning '224' as column: COUNTRY2_1_
10:44:18,546 DEBUG DefaultLoadEventListener: loading entity: [org.lds.stack.petstore.model.Country#224]
10:44:18,546 DEBUG DefaultLoadEventListener: attempting to resolve: [org.lds.stack.petstore.model.Country#224]
10:44:18,546 DEBUG DefaultLoadEventListener: resolved object in session cache: [org.lds.stack.petstore.model.Country#224]
10:44:18,546 DEBUG Loader: result set row: 87
10:44:18,546 DEBUG LongType: returning '224' as column: id3_0_
10:44:18,546 DEBUG Loader: result row: EntityKey[org.lds.stack.petstore.model.Country#224]
10:44:18,546 DEBUG LongType: returning '13' as column: ANIMAL1_1_
10:44:18,546 DEBUG Loader: found row of collection: [org.lds.stack.petstore.model.Animal.countries#13]
10:44:18,546 DEBUG CollectionLoadContext: reading row
10:44:18,546 DEBUG LongType: returning '224' as column: COUNTRY2_1_
10:44:18,546 DEBUG DefaultLoadEventListener: loading entity: [org.lds.stack.petstore.model.Country#224]
10:44:18,546 DEBUG DefaultLoadEventListener: attempting to resolve: [org.lds.stack.petstore.model.Country#224]
10:44:18,546 DEBUG DefaultLoadEventListener: resolved object in session cache: [org.lds.stack.petstore.model.Country#224]
10:44:18,546 DEBUG Loader: result set row: 88
10:44:18,546 DEBUG LongType: returning '224' as column: id3_0_
10:44:18,546 DEBUG Loader: result row: EntityKey[org.lds.stack.petstore.model.Country#224]
10:44:18,546 DEBUG LongType: returning '12' as column: ANIMAL1_1_
10:44:18,546 DEBUG Loader: found row of collection: [org.lds.stack.petstore.model.Animal.countries#12]
10:44:18,546 DEBUG CollectionLoadContext: reading row
10:44:18,546 DEBUG LongType: returning '224' as column: COUNTRY2_1_
10:44:18,546 DEBUG DefaultLoadEventListener: loading entity: [org.lds.stack.petstore.model.Country#224]
10:44:18,546 DEBUG DefaultLoadEventListener: attempting to resolve: [org.lds.stack.petstore.model.Country#224]
10:44:18,546 DEBUG DefaultLoadEventListener: resolved object in session cache: [org.lds.stack.petstore.model.Country#224]
10:44:18,546 DEBUG Loader: result set row: 89
10:44:18,546 DEBUG LongType: returning '224' as column: id3_0_
10:44:18,546 DEBUG Loader: result row: EntityKey[org.lds.stack.petstore.model.Country#224]
10:44:18,546 DEBUG LongType: returning '11' as column: ANIMAL1_1_
10:44:18,546 DEBUG Loader: found row of collection: [org.lds.stack.petstore.model.Animal.countries#11]
10:44:18,546 DEBUG CollectionLoadContext: reading row
10:44:18,546 DEBUG LongType: returning '224' as column: COUNTRY2_1_
10:44:18,546 DEBUG DefaultLoadEventListener: loading entity: [org.lds.stack.petstore.model.Country#224]
10:44:18,546 DEBUG DefaultLoadEventListener: attempting to resolve: [org.lds.stack.petstore.model.Country#224]
10:44:18,546 DEBUG DefaultLoadEventListener: resolved object in session cache: [org.lds.stack.petstore.model.Country#224]
10:44:18,546 DEBUG Loader: result set row: 90
10:44:18,546 DEBUG LongType: returning '224' as column: id3_0_
10:44:18,562 DEBUG Loader: result row: EntityKey[org.lds.stack.petstore.model.Country#224]
10:44:18,562 DEBUG LongType: returning '10' as column: ANIMAL1_1_
10:44:18,562 DEBUG Loader: found row of collection: [org.lds.stack.petstore.model.Animal.countries#10]
10:44:18,562 DEBUG CollectionLoadContext: reading row
10:44:18,562 DEBUG LongType: returning '224' as column: COUNTRY2_1_
10:44:18,562 DEBUG DefaultLoadEventListener: loading entity: [org.lds.stack.petstore.model.Country#224]
10:44:18,562 DEBUG DefaultLoadEventListener: attempting to resolve: [org.lds.stack.petstore.model.Country#224]
10:44:18,562 DEBUG DefaultLoadEventListener: resolved object in session cache: [org.lds.stack.petstore.model.Country#224]
10:44:18,562 DEBUG Loader: result set row: 91
10:44:18,562 DEBUG LongType: returning '224' as column: id3_0_
10:44:18,562 DEBUG Loader: result row: EntityKey[org.lds.stack.petstore.model.Country#224]
10:44:18,562 DEBUG LongType: returning '9' as column: ANIMAL1_1_
10:44:18,562 DEBUG Loader: found row of collection: [org.lds.stack.petstore.model.Animal.countries#9]
10:44:18,562 DEBUG CollectionLoadContext: reading row
10:44:18,562 DEBUG LongType: returning '224' as column: COUNTRY2_1_
10:44:18,562 DEBUG DefaultLoadEventListener: loading entity: [org.lds.stack.petstore.model.Country#224]
10:44:18,562 DEBUG DefaultLoadEventListener: attempting to resolve: [org.lds.stack.petstore.model.Country#224]
10:44:18,562 DEBUG DefaultLoadEventListener: resolved object in session cache: [org.lds.stack.petstore.model.Country#224]
10:44:18,562 DEBUG Loader: result set row: 92
10:44:18,562 DEBUG LongType: returning '224' as column: id3_0_
10:44:18,562 DEBUG Loader: result row: EntityKey[org.lds.stack.petstore.model.Country#224]
10:44:18,562 DEBUG LongType: returning '57' as column: ANIMAL1_1_
10:44:18,562 DEBUG Loader: found row of collection: [org.lds.stack.petstore.model.Animal.countries#57]
10:44:18,562 DEBUG CollectionLoadContext: new collection: instantiating
10:44:18,562 DEBUG LongType: returning '224' as column: COUNTRY2_1_
10:44:18,562 DEBUG DefaultLoadEventListener: loading entity: [org.lds.stack.petstore.model.Country#224]
10:44:18,562 DEBUG DefaultLoadEventListener: attempting to resolve: [org.lds.stack.petstore.model.Country#224]
10:44:18,562 DEBUG DefaultLoadEventListener: resolved object in session cache: [org.lds.stack.petstore.model.Country#224]
10:44:18,562 DEBUG Loader: result set row: 93
10:44:18,562 DEBUG LongType: returning '224' as column: id3_0_
10:44:18,562 DEBUG Loader: result row: EntityKey[org.lds.stack.petstore.model.Country#224]
10:44:18,562 DEBUG LongType: returning '56' as column: ANIMAL1_1_
10:44:18,562 DEBUG Loader: found row of collection: [org.lds.stack.petstore.model.Animal.countries#56]
10:44:18,562 DEBUG CollectionLoadContext: new collection: instantiating
10:44:18,562 DEBUG LongType: returning '224' as column: COUNTRY2_1_
10:44:18,562 DEBUG DefaultLoadEventListener: loading entity: [org.lds.stack.petstore.model.Country#224]
10:44:18,562 DEBUG DefaultLoadEventListener: attempting to resolve: [org.lds.stack.petstore.model.Country#224]
10:44:18,562 DEBUG DefaultLoadEventListener: resolved object in session cache: [org.lds.stack.petstore.model.Country#224]
10:44:18,562 DEBUG Loader: result set row: 94
10:44:18,562 DEBUG LongType: returning '224' as column: id3_0_
10:44:18,562 DEBUG Loader: result row: EntityKey[org.lds.stack.petstore.model.Country#224]
10:44:18,562 DEBUG LongType: returning '51' as column: ANIMAL1_1_
10:44:18,562 DEBUG Loader: found row of collection: [org.lds.stack.petstore.model.Animal.countries#51]
10:44:18,562 DEBUG CollectionLoadContext: reading row
10:44:18,562 DEBUG LongType: returning '224' as column: COUNTRY2_1_
10:44:18,562 DEBUG DefaultLoadEventListener: loading entity: [org.lds.stack.petstore.model.Country#224]
10:44:18,562 DEBUG DefaultLoadEventListener: attempting to resolve: [org.lds.stack.petstore.model.Country#224]
10:44:18,562 DEBUG DefaultLoadEventListener: resolved object in session cache: [org.lds.stack.petstore.model.Country#224]
10:44:18,562 DEBUG Loader: result set row: 95
10:44:18,562 DEBUG LongType: returning '224' as column: id3_0_
10:44:18,562 DEBUG Loader: result row: EntityKey[org.lds.stack.petstore.model.Country#224]
10:44:18,562 DEBUG LongType: returning '35' as column: ANIMAL1_1_
10:44:18,562 DEBUG Loader: found row of collection: [org.lds.stack.petstore.model.Animal.countries#35]
10:44:18,562 DEBUG CollectionLoadContext: reading row
10:44:18,562 DEBUG LongType: returning '224' as column: COUNTRY2_1_
10:44:18,562 DEBUG DefaultLoadEventListener: loading entity: [org.lds.stack.petstore.model.Country#224]
10:44:18,562 DEBUG DefaultLoadEventListener: attempting to resolve: [org.lds.stack.petstore.model.Country#224]
10:44:18,562 DEBUG DefaultLoadEventListener: resolved object in session cache: [org.lds.stack.petstore.model.Country#224]
10:44:18,562 DEBUG Loader: result set row: 96
10:44:18,562 DEBUG LongType: returning '224' as column: id3_0_
10:44:18,562 DEBUG Loader: result row: EntityKey[org.lds.stack.petstore.model.Country#224]
10:44:18,562 DEBUG LongType: returning '34' as column: ANIMAL1_1_
10:44:18,562 DEBUG Loader: found row of collection: [org.lds.stack.petstore.model.Animal.countries#34]
10:44:18,562 DEBUG CollectionLoadContext: new collection: instantiating
10:44:18,562 DEBUG LongType: returning '224' as column: COUNTRY2_1_
10:44:18,562 DEBUG DefaultLoadEventListener: loading entity: [org.lds.stack.petstore.model.Country#224]
10:44:18,562 DEBUG DefaultLoadEventListener: attempting to resolve: [org.lds.stack.petstore.model.Country#224]
10:44:18,562 DEBUG DefaultLoadEventListener: resolved object in session cache: [org.lds.stack.petstore.model.Country#224]
10:44:18,562 DEBUG Loader: result set row: 97
10:44:18,562 DEBUG LongType: returning '224' as column: id3_0_
10:44:18,562 DEBUG Loader: result row: EntityKey[org.lds.stack.petstore.model.Country#224]
10:44:18,562 DEBUG LongType: returning '32' as column: ANIMAL1_1_
10:44:18,562 DEBUG Loader: found row of collection: [org.lds.stack.petstore.model.Animal.countries#32]
10:44:18,562 DEBUG CollectionLoadContext: new collection: instantiating
10:44:18,562 DEBUG LongType: returning '224' as column: COUNTRY2_1_
10:44:18,562 DEBUG DefaultLoadEventListener: loading entity: [org.lds.stack.petstore.model.Country#224]
10:44:18,562 DEBUG DefaultLoadEventListener: attempting to resolve: [org.lds.stack.petstore.model.Country#224]
10:44:18,562 DEBUG DefaultLoadEventListener: resolved object in session cache: [org.lds.stack.petstore.model.Country#224]
10:44:18,562 DEBUG Loader: result set row: 98
10:44:18,562 DEBUG LongType: returning '224' as column: id3_0_
10:44:18,562 DEBUG Loader: result row: EntityKey[org.lds.stack.petstore.model.Country#224]
10:44:18,562 DEBUG LongType: returning '30' as column: ANIMAL1_1_
10:44:18,562 DEBUG Loader: found row of collection: [org.lds.stack.petstore.model.Animal.countries#30]
10:44:18,562 DEBUG CollectionLoadContext: reading row
10:44:18,562 DEBUG LongType: returning '224' as column: COUNTRY2_1_
10:44:18,562 DEBUG DefaultLoadEventListener: loading entity: [org.lds.stack.petstore.model.Country#224]
10:44:18,562 DEBUG DefaultLoadEventListener: attempting to resolve: [org.lds.stack.petstore.model.Country#224]
10:44:18,562 DEBUG DefaultLoadEventListener: resolved object in session cache: [org.lds.stack.petstore.model.Country#224]
10:44:18,562 DEBUG Loader: result set row: 99
10:44:18,562 DEBUG LongType: returning '224' as column: id3_0_
10:44:18,562 DEBUG Loader: result row: EntityKey[org.lds.stack.petstore.model.Country#224]
10:44:18,562 DEBUG LongType: returning '29' as column: ANIMAL1_1_
10:44:18,562 DEBUG Loader: found row of collection: [org.lds.stack.petstore.model.Animal.countries#29]
10:44:18,562 DEBUG CollectionLoadContext: new collection: instantiating
10:44:18,562 DEBUG LongType: returning '224' as column: COUNTRY2_1_
10:44:18,562 DEBUG DefaultLoadEventListener: loading entity: [org.lds.stack.petstore.model.Country#224]
10:44:18,562 DEBUG DefaultLoadEventListener: attempting to resolve: [org.lds.stack.petstore.model.Country#224]
10:44:18,562 DEBUG DefaultLoadEventListener: resolved object in session cache: [org.lds.stack.petstore.model.Country#224]
10:44:18,562 DEBUG Loader: result set row: 100
10:44:18,562 DEBUG LongType: returning '224' as column: id3_0_
10:44:18,562 DEBUG Loader: result row: EntityKey[org.lds.stack.petstore.model.Country#224]
10:44:18,562 DEBUG LongType: returning '28' as column: ANIMAL1_1_
10:44:18,562 DEBUG Loader: found row of collection: [org.lds.stack.petstore.model.Animal.countries#28]
10:44:18,562 DEBUG CollectionLoadContext: new collection: instantiating
10:44:18,562 DEBUG LongType: returning '224' as column: COUNTRY2_1_
10:44:18,562 DEBUG DefaultLoadEventListener: loading entity: [org.lds.stack.petstore.model.Country#224]
10:44:18,562 DEBUG DefaultLoadEventListener: attempting to resolve: [org.lds.stack.petstore.model.Country#224]
10:44:18,562 DEBUG DefaultLoadEventListener: resolved object in session cache: [org.lds.stack.petstore.model.Country#224]
10:44:18,562 DEBUG Loader: result set row: 101
10:44:18,562 DEBUG LongType: returning '224' as column: id3_0_
10:44:18,562 DEBUG Loader: result row: EntityKey[org.lds.stack.petstore.model.Country#224]
10:44:18,562 DEBUG LongType: returning '27' as column: ANIMAL1_1_
10:44:18,562 DEBUG Loader: found row of collection: [org.lds.stack.petstore.model.Animal.countries#27]
10:44:18,562 DEBUG CollectionLoadContext: new collection: instantiating
10:44:18,562 DEBUG LongType: returning '224' as column: COUNTRY2_1_
10:44:18,562 DEBUG DefaultLoadEventListener: loading entity: [org.lds.stack.petstore.model.Country#224]
10:44:18,562 DEBUG DefaultLoadEventListener: attempting to resolve: [org.lds.stack.petstore.model.Country#224]
10:44:18,562 DEBUG DefaultLoadEventListener: resolved object in session cache: [org.lds.stack.petstore.model.Country#224]
10:44:18,562 DEBUG Loader: result set row: 102
10:44:18,562 DEBUG LongType: returning '224' as column: id3_0_
10:44:18,562 DEBUG Loader: result row: EntityKey[org.lds.stack.petstore.model.Country#224]
10:44:18,562 DEBUG LongType: returning '26' as column: ANIMAL1_1_
10:44:18,562 DEBUG Loader: found row of collection: [org.lds.stack.petstore.model.Animal.countries#26]
10:44:18,562 DEBUG CollectionLoadContext: new collection: instantiating
10:44:18,562 DEBUG LongType: returning '224' as column: COUNTRY2_1_
10:44:18,562 DEBUG DefaultLoadEventListener: loading entity: [org.lds.stack.petstore.model.Country#224]
10:44:18,562 DEBUG DefaultLoadEventListener: attempting to resolve: [org.lds.stack.petstore.model.Country#224]
10:44:18,562 DEBUG DefaultLoadEventListener: resolved object in session cache: [org.lds.stack.petstore.model.Country#224]
10:44:18,562 DEBUG Loader: result set row: 103
10:44:18,562 DEBUG LongType: returning '224' as column: id3_0_
10:44:18,562 DEBUG Loader: result row: EntityKey[org.lds.stack.petstore.model.Country#224]
10:44:18,562 DEBUG LongType: returning '25' as column: ANIMAL1_1_
10:44:18,562 DEBUG Loader: found row of collection: [org.lds.stack.petstore.model.Animal.countries#25]
10:44:18,562 DEBUG CollectionLoadContext: reading row
10:44:18,562 DEBUG LongType: returning '224' as column: COUNTRY2_1_
10:44:18,562 DEBUG DefaultLoadEventListener: loading entity: [org.lds.stack.petstore.model.Country#224]
10:44:18,562 DEBUG DefaultLoadEventListener: attempting to resolve: [org.lds.stack.petstore.model.Country#224]
10:44:18,562 DEBUG DefaultLoadEventListener: resolved object in session cache: [org.lds.stack.petstore.model.Country#224]
10:44:18,562 DEBUG Loader: result set row: 104
10:44:18,562 DEBUG LongType: returning '224' as column: id3_0_
10:44:18,562 DEBUG Loader: result row: EntityKey[org.lds.stack.petstore.model.Country#224]
10:44:18,562 DEBUG LongType: returning '48' as column: ANIMAL1_1_
10:44:18,562 DEBUG Loader: found row of collection: [org.lds.stack.petstore.model.Animal.countries#48]
10:44:18,562 DEBUG CollectionLoadContext: new collection: instantiating
10:44:18,562 DEBUG LongType: returning '224' as column: COUNTRY2_1_
10:44:18,562 DEBUG DefaultLoadEventListener: loading entity: [org.lds.stack.petstore.model.Country#224]
10:44:18,562 DEBUG DefaultLoadEventListener: attempting to resolve: [org.lds.stack.petstore.model.Country#224]
10:44:18,562 DEBUG DefaultLoadEventListener: resolved object in session cache: [org.lds.stack.petstore.model.Country#224]
10:44:18,562 DEBUG Loader: result set row: 105
10:44:18,562 DEBUG LongType: returning '224' as column: id3_0_
10:44:18,562 DEBUG Loader: result row: EntityKey[org.lds.stack.petstore.model.Country#224]
10:44:18,562 DEBUG LongType: returning '46' as column: ANIMAL1_1_
10:44:18,562 DEBUG Loader: found row of collection: [org.lds.stack.petstore.model.Animal.countries#46]
10:44:18,562 DEBUG CollectionLoadContext: reading row
10:44:18,562 DEBUG LongType: returning '224' as column: COUNTRY2_1_
10:44:18,562 DEBUG DefaultLoadEventListener: loading entity: [org.lds.stack.petstore.model.Country#224]
10:44:18,562 DEBUG DefaultLoadEventListener: attempting to resolve: [org.lds.stack.petstore.model.Country#224]
10:44:18,562 DEBUG DefaultLoadEventListener: resolved object in session cache: [org.lds.stack.petstore.model.Country#224]
10:44:18,562 DEBUG Loader: result set row: 106
10:44:18,562 DEBUG LongType: returning '224' as column: id3_0_
10:44:18,562 DEBUG Loader: result row: EntityKey[org.lds.stack.petstore.model.Country#224]
10:44:18,562 DEBUG LongType: returning '8' as column: ANIMAL1_1_
10:44:18,562 DEBUG Loader: found row of collection: [org.lds.stack.petstore.model.Animal.countries#8]
10:44:18,562 DEBUG CollectionLoadContext: reading row
10:44:18,562 DEBUG LongType: returning '224' as column: COUNTRY2_1_
10:44:18,562 DEBUG DefaultLoadEventListener: loading entity: [org.lds.stack.petstore.model.Country#224]
10:44:18,562 DEBUG DefaultLoadEventListener: attempting to resolve: [org.lds.stack.petstore.model.Country#224]
10:44:18,562 DEBUG DefaultLoadEventListener: resolved object in session cache: [org.lds.stack.petstore.model.Country#224]
10:44:18,562 DEBUG Loader: result set row: 107
10:44:18,562 DEBUG LongType: returning '224' as column: id3_0_
10:44:18,562 DEBUG Loader: result row: EntityKey[org.lds.stack.petstore.model.Country#224]
10:44:18,562 DEBUG LongType: returning '7' as column: ANIMAL1_1_
10:44:18,562 DEBUG Loader: found row of collection: [org.lds.stack.petstore.model.Animal.countries#7]
10:44:18,562 DEBUG CollectionLoadContext: reading row
10:44:18,562 DEBUG LongType: returning '224' as column: COUNTRY2_1_
10:44:18,562 DEBUG DefaultLoadEventListener: loading entity: [org.lds.stack.petstore.model.Country#224]
10:44:18,562 DEBUG DefaultLoadEventListener: attempting to resolve: [org.lds.stack.petstore.model.Country#224]
10:44:18,562 DEBUG DefaultLoadEventListener: resolved object in session cache: [org.lds.stack.petstore.model.Country#224]
10:44:18,562 DEBUG Loader: result set row: 108
10:44:18,562 DEBUG LongType: returning '224' as column: id3_0_
10:44:18,562 DEBUG Loader: result row: EntityKey[org.lds.stack.petstore.model.Country#224]
10:44:18,562 DEBUG LongType: returning '6' as column: ANIMAL1_1_
10:44:18,562 DEBUG Loader: found row of collection: [org.lds.stack.petstore.model.Animal.countries#6]
10:44:18,562 DEBUG CollectionLoadContext: reading row
10:44:18,562 DEBUG LongType: returning '224' as column: COUNTRY2_1_
10:44:18,562 DEBUG DefaultLoadEventListener: loading entity: [org.lds.stack.petstore.model.Country#224]
10:44:18,562 DEBUG DefaultLoadEventListener: attempting to resolve: [org.lds.stack.petstore.model.Country#224]
10:44:18,562 DEBUG DefaultLoadEventListener: resolved object in session cache: [org.lds.stack.petstore.model.Country#224]
10:44:18,562 DEBUG Loader: result set row: 109
10:44:18,562 DEBUG LongType: returning '224' as column: id3_0_
10:44:18,562 DEBUG Loader: result row: EntityKey[org.lds.stack.petstore.model.Country#224]
10:44:18,562 DEBUG LongType: returning '5' as column: ANIMAL1_1_
10:44:18,562 DEBUG Loader: found row of collection: [org.lds.stack.petstore.model.Animal.countries#5]
10:44:18,562 DEBUG CollectionLoadContext: reading row
10:44:18,562 DEBUG LongType: returning '224' as column: COUNTRY2_1_
10:44:18,562 DEBUG DefaultLoadEventListener: loading entity: [org.lds.stack.petstore.model.Country#224]
10:44:18,562 DEBUG DefaultLoadEventListener: attempting to resolve: [org.lds.stack.petstore.model.Country#224]
10:44:18,562 DEBUG DefaultLoadEventListener: resolved object in session cache: [org.lds.stack.petstore.model.Country#224]
10:44:18,562 DEBUG Loader: result set row: 110
10:44:18,562 DEBUG LongType: returning '224' as column: id3_0_
10:44:18,562 DEBUG Loader: result row: EntityKey[org.lds.stack.petstore.model.Country#224]
10:44:18,562 DEBUG LongType: returning '4' as column: ANIMAL1_1_
10:44:18,562 DEBUG Loader: found row of collection: [org.lds.stack.petstore.model.Animal.countries#4]
10:44:18,562 DEBUG CollectionLoadContext: reading row
10:44:18,562 DEBUG LongType: returning '224' as column: COUNTRY2_1_
10:44:18,562 DEBUG DefaultLoadEventListener: loading entity: [org.lds.stack.petstore.model.Country#224]
10:44:18,562 DEBUG DefaultLoadEventListener: attempting to resolve: [org.lds.stack.petstore.model.Country#224]
10:44:18,562 DEBUG DefaultLoadEventListener: resolved object in session cache: [org.lds.stack.petstore.model.Country#224]
10:44:18,562 DEBUG Loader: result set row: 111
10:44:18,562 DEBUG LongType: returning '224' as column: id3_0_
10:44:18,562 DEBUG Loader: result row: EntityKey[org.lds.stack.petstore.model.Country#224]
10:44:18,562 DEBUG LongType: returning '3' as column: ANIMAL1_1_
10:44:18,562 DEBUG Loader: found row of collection: [org.lds.stack.petstore.model.Animal.countries#3]
10:44:18,562 DEBUG CollectionLoadContext: reading row
10:44:18,562 DEBUG LongType: returning '224' as column: COUNTRY2_1_
10:44:18,562 DEBUG DefaultLoadEventListener: loading entity: [org.lds.stack.petstore.model.Country#224]
10:44:18,562 DEBUG DefaultLoadEventListener: attempting to resolve: [org.lds.stack.petstore.model.Country#224]
10:44:18,562 DEBUG DefaultLoadEventListener: resolved object in session cache: [org.lds.stack.petstore.model.Country#224]
10:44:18,562 DEBUG Loader: result set row: 112
10:44:18,562 DEBUG LongType: returning '224' as column: id3_0_
10:44:18,562 DEBUG Loader: result row: EntityKey[org.lds.stack.petstore.model.Country#224]
10:44:18,562 DEBUG LongType: returning '2' as column: ANIMAL1_1_
10:44:18,562 DEBUG Loader: found row of collection: [org.lds.stack.petstore.model.Animal.countries#2]
10:44:18,562 DEBUG CollectionLoadContext: reading row
10:44:18,562 DEBUG LongType: returning '224' as column: COUNTRY2_1_
10:44:18,562 DEBUG DefaultLoadEventListener: loading entity: [org.lds.stack.petstore.model.Country#224]
10:44:18,562 DEBUG DefaultLoadEventListener: attempting to resolve: [org.lds.stack.petstore.model.Country#224]
10:44:18,562 DEBUG DefaultLoadEventListener: resolved object in session cache: [org.lds.stack.petstore.model.Country#224]
10:44:18,562 DEBUG Loader: result set row: 113
10:44:18,562 DEBUG LongType: returning '225' as column: id3_0_
10:44:18,562 DEBUG Loader: result row: EntityKey[org.lds.stack.petstore.model.Country#225]
10:44:18,562 DEBUG Loader: Initializing object from ResultSet: [org.lds.stack.petstore.model.Country#225]
10:44:18,562 DEBUG AbstractEntityPersister: Hydrating entity: [org.lds.stack.petstore.model.Country#225]
10:44:18,562 DEBUG StringType: returning 'United States' as column: name3_0_
10:44:18,562 DEBUG LongType: returning '1' as column: ANIMAL1_1_
10:44:18,562 DEBUG Loader: found row of collection: [org.lds.stack.petstore.model.Animal.countries#1]
10:44:18,562 DEBUG CollectionLoadContext: reading row
10:44:18,562 DEBUG LongType: returning '225' as column: COUNTRY2_1_
10:44:18,562 DEBUG DefaultLoadEventListener: loading entity: [org.lds.stack.petstore.model.Country#225]
10:44:18,562 DEBUG DefaultLoadEventListener: attempting to resolve: [org.lds.stack.petstore.model.Country#225]
10:44:18,562 DEBUG DefaultLoadEventListener: resolved object in session cache: [org.lds.stack.petstore.model.Country#225]
10:44:18,562 DEBUG Loader: result set row: 114
10:44:18,562 DEBUG LongType: returning '225' as column: id3_0_
10:44:18,562 DEBUG Loader: result row: EntityKey[org.lds.stack.petstore.model.Country#225]
10:44:18,562 DEBUG LongType: returning '16' as column: ANIMAL1_1_
10:44:18,562 DEBUG Loader: found row of collection: [org.lds.stack.petstore.model.Animal.countries#16]
10:44:18,562 DEBUG CollectionLoadContext: reading row
10:44:18,562 DEBUG LongType: returning '225' as column: COUNTRY2_1_
10:44:18,562 DEBUG DefaultLoadEventListener: loading entity: [org.lds.stack.petstore.model.Country#225]
10:44:18,562 DEBUG DefaultLoadEventListener: attempting to resolve: [org.lds.stack.petstore.model.Country#225]
10:44:18,562 DEBUG DefaultLoadEventListener: resolved object in session cache: [org.lds.stack.petstore.model.Country#225]
10:44:18,562 DEBUG Loader: result set row: 115
10:44:18,562 DEBUG LongType: returning '225' as column: id3_0_
10:44:18,578 DEBUG Loader: result row: EntityKey[org.lds.stack.petstore.model.Country#225]
10:44:18,578 DEBUG LongType: returning '15' as column: ANIMAL1_1_
10:44:18,578 DEBUG Loader: found row of collection: [org.lds.stack.petstore.model.Animal.countries#15]
10:44:18,578 DEBUG CollectionLoadContext: reading row
10:44:18,578 DEBUG LongType: returning '225' as column: COUNTRY2_1_
10:44:18,578 DEBUG DefaultLoadEventListener: loading entity: [org.lds.stack.petstore.model.Country#225]
10:44:18,578 DEBUG DefaultLoadEventListener: attempting to resolve: [org.lds.stack.petstore.model.Country#225]
10:44:18,578 DEBUG DefaultLoadEventListener: resolved object in session cache: [org.lds.stack.petstore.model.Country#225]
10:44:18,578 DEBUG Loader: result set row: 116
10:44:18,578 DEBUG LongType: returning '225' as column: id3_0_
10:44:18,578 DEBUG Loader: result row: EntityKey[org.lds.stack.petstore.model.Country#225]
10:44:18,578 DEBUG LongType: returning '14' as column: ANIMAL1_1_
10:44:18,578 DEBUG Loader: found row of collection: [org.lds.stack.petstore.model.Animal.countries#14]
10:44:18,578 DEBUG CollectionLoadContext: reading row
10:44:18,578 DEBUG LongType: returning '225' as column: COUNTRY2_1_
10:44:18,578 DEBUG DefaultLoadEventListener: loading entity: [org.lds.stack.petstore.model.Country#225]
10:44:18,578 DEBUG DefaultLoadEventListener: attempting to resolve: [org.lds.stack.petstore.model.Country#225]
10:44:18,578 DEBUG DefaultLoadEventListener: resolved object in session cache: [org.lds.stack.petstore.model.Country#225]
10:44:18,578 DEBUG Loader: result set row: 117
10:44:18,578 DEBUG LongType: returning '225' as column: id3_0_
10:44:18,578 DEBUG Loader: result row: EntityKey[org.lds.stack.petstore.model.Country#225]
10:44:18,578 DEBUG LongType: returning '13' as column: ANIMAL1_1_
10:44:18,578 DEBUG Loader: found row of collection: [org.lds.stack.petstore.model.Animal.countries#13]
10:44:18,578 DEBUG CollectionLoadContext: reading row
10:44:18,578 DEBUG LongType: returning '225' as column: COUNTRY2_1_
10:44:18,578 DEBUG DefaultLoadEventListener: loading entity: [org.lds.stack.petstore.model.Country#225]
10:44:18,578 DEBUG DefaultLoadEventListener: attempting to resolve: [org.lds.stack.petstore.model.Country#225]
10:44:18,578 DEBUG DefaultLoadEventListener: resolved object in session cache: [org.lds.stack.petstore.model.Country#225]
10:44:18,578 DEBUG Loader: result set row: 118
10:44:18,578 DEBUG LongType: returning '225' as column: id3_0_
10:44:18,578 DEBUG Loader: result row: EntityKey[org.lds.stack.petstore.model.Country#225]
10:44:18,578 DEBUG LongType: returning '12' as column: ANIMAL1_1_
10:44:18,578 DEBUG Loader: found row of collection: [org.lds.stack.petstore.model.Animal.countries#12]
10:44:18,578 DEBUG CollectionLoadContext: reading row
10:44:18,578 DEBUG LongType: returning '225' as column: COUNTRY2_1_
10:44:18,578 DEBUG DefaultLoadEventListener: loading entity: [org.lds.stack.petstore.model.Country#225]
10:44:18,578 DEBUG DefaultLoadEventListener: attempting to resolve: [org.lds.stack.petstore.model.Country#225]
10:44:18,578 DEBUG DefaultLoadEventListener: resolved object in session cache: [org.lds.stack.petstore.model.Country#225]
10:44:18,578 DEBUG Loader: result set row: 119
10:44:18,578 DEBUG LongType: returning '225' as column: id3_0_
10:44:18,578 DEBUG Loader: result row: EntityKey[org.lds.stack.petstore.model.Country#225]
10:44:18,578 DEBUG LongType: returning '11' as column: ANIMAL1_1_
10:44:18,578 DEBUG Loader: found row of collection: [org.lds.stack.petstore.model.Animal.countries#11]
10:44:18,578 DEBUG CollectionLoadContext: reading row
10:44:18,578 DEBUG LongType: returning '225' as column: COUNTRY2_1_
10:44:18,578 DEBUG DefaultLoadEventListener: loading entity: [org.lds.stack.petstore.model.Country#225]
10:44:18,578 DEBUG DefaultLoadEventListener: attempting to resolve: [org.lds.stack.petstore.model.Country#225]
10:44:18,578 DEBUG DefaultLoadEventListener: resolved object in session cache: [org.lds.stack.petstore.model.Country#225]
10:44:18,578 DEBUG Loader: result set row: 120
10:44:18,578 DEBUG LongType: returning '225' as column: id3_0_
10:44:18,578 DEBUG Loader: result row: EntityKey[org.lds.stack.petstore.model.Country#225]
10:44:18,578 DEBUG LongType: returning '10' as column: ANIMAL1_1_
10:44:18,578 DEBUG Loader: found row of collection: [org.lds.stack.petstore.model.Animal.countries#10]
10:44:18,578 DEBUG CollectionLoadContext: reading row
10:44:18,578 DEBUG LongType: returning '225' as column: COUNTRY2_1_
10:44:18,578 DEBUG DefaultLoadEventListener: loading entity: [org.lds.stack.petstore.model.Country#225]
10:44:18,578 DEBUG DefaultLoadEventListener: attempting to resolve: [org.lds.stack.petstore.model.Country#225]
10:44:18,578 DEBUG DefaultLoadEventListener: resolved object in session cache: [org.lds.stack.petstore.model.Country#225]
10:44:18,578 DEBUG Loader: result set row: 121
10:44:18,578 DEBUG LongType: returning '225' as column: id3_0_
10:44:18,578 DEBUG Loader: result row: EntityKey[org.lds.stack.petstore.model.Country#225]
10:44:18,578 DEBUG LongType: returning '9' as column: ANIMAL1_1_
10:44:18,578 DEBUG Loader: found row of collection: [org.lds.stack.petstore.model.Animal.countries#9]
10:44:18,578 DEBUG CollectionLoadContext: reading row
10:44:18,578 DEBUG LongType: returning '225' as column: COUNTRY2_1_
10:44:18,578 DEBUG DefaultLoadEventListener: loading entity: [org.lds.stack.petstore.model.Country#225]
10:44:18,578 DEBUG DefaultLoadEventListener: attempting to resolve: [org.lds.stack.petstore.model.Country#225]
10:44:18,578 DEBUG DefaultLoadEventListener: resolved object in session cache: [org.lds.stack.petstore.model.Country#225]
10:44:18,578 DEBUG Loader: result set row: 122
10:44:18,578 DEBUG LongType: returning '225' as column: id3_0_
10:44:18,578 DEBUG Loader: result row: EntityKey[org.lds.stack.petstore.model.Country#225]
10:44:18,578 DEBUG LongType: returning '8' as column: ANIMAL1_1_
10:44:18,578 DEBUG Loader: found row of collection: [org.lds.stack.petstore.model.Animal.countries#8]
10:44:18,578 DEBUG CollectionLoadContext: reading row
10:44:18,578 DEBUG LongType: returning '225' as column: COUNTRY2_1_
10:44:18,578 DEBUG DefaultLoadEventListener: loading entity: [org.lds.stack.petstore.model.Country#225]
10:44:18,578 DEBUG DefaultLoadEventListener: attempting to resolve: [org.lds.stack.petstore.model.Country#225]
10:44:18,578 DEBUG DefaultLoadEventListener: resolved object in session cache: [org.lds.stack.petstore.model.Country#225]
10:44:18,578 DEBUG Loader: result set row: 123
10:44:18,578 DEBUG LongType: returning '225' as column: id3_0_
10:44:18,578 DEBUG Loader: result row: EntityKey[org.lds.stack.petstore.model.Country#225]
10:44:18,578 DEBUG LongType: returning '7' as column: ANIMAL1_1_
10:44:18,578 DEBUG Loader: found row of collection: [org.lds.stack.petstore.model.Animal.countries#7]
10:44:18,578 DEBUG CollectionLoadContext: reading row
10:44:18,578 DEBUG LongType: returning '225' as column: COUNTRY2_1_
10:44:18,578 DEBUG DefaultLoadEventListener: loading entity: [org.lds.stack.petstore.model.Country#225]
10:44:18,578 DEBUG DefaultLoadEventListener: attempting to resolve: [org.lds.stack.petstore.model.Country#225]
10:44:18,578 DEBUG DefaultLoadEventListener: resolved object in session cache: [org.lds.stack.petstore.model.Country#225]
10:44:18,578 DEBUG Loader: result set row: 124
10:44:18,578 DEBUG LongType: returning '225' as column: id3_0_
10:44:18,578 DEBUG Loader: result row: EntityKey[org.lds.stack.petstore.model.Country#225]
10:44:18,578 DEBUG LongType: returning '6' as column: ANIMAL1_1_
10:44:18,578 DEBUG Loader: found row of collection: [org.lds.stack.petstore.model.Animal.countries#6]
10:44:18,578 DEBUG CollectionLoadContext: reading row
10:44:18,578 DEBUG LongType: returning '225' as column: COUNTRY2_1_
10:44:18,578 DEBUG DefaultLoadEventListener: loading entity: [org.lds.stack.petstore.model.Country#225]
10:44:18,578 DEBUG DefaultLoadEventListener: attempting to resolve: [org.lds.stack.petstore.model.Country#225]
10:44:18,578 DEBUG DefaultLoadEventListener: resolved object in session cache: [org.lds.stack.petstore.model.Country#225]
10:44:18,578 DEBUG Loader: result set row: 125
10:44:18,578 DEBUG LongType: returning '225' as column: id3_0_
10:44:18,578 DEBUG Loader: result row: EntityKey[org.lds.stack.petstore.model.Country#225]
10:44:18,578 DEBUG LongType: returning '5' as column: ANIMAL1_1_
10:44:18,578 DEBUG Loader: found row of collection: [org.lds.stack.petstore.model.Animal.countries#5]
10:44:18,578 DEBUG CollectionLoadContext: reading row
10:44:18,578 DEBUG LongType: returning '225' as column: COUNTRY2_1_
10:44:18,578 DEBUG DefaultLoadEventListener: loading entity: [org.lds.stack.petstore.model.Country#225]
10:44:18,578 DEBUG DefaultLoadEventListener: attempting to resolve: [org.lds.stack.petstore.model.Country#225]
10:44:18,578 DEBUG DefaultLoadEventListener: resolved object in session cache: [org.lds.stack.petstore.model.Country#225]
10:44:18,578 DEBUG Loader: result set row: 126
10:44:18,578 DEBUG LongType: returning '225' as column: id3_0_
10:44:18,578 DEBUG Loader: result row: EntityKey[org.lds.stack.petstore.model.Country#225]
10:44:18,578 DEBUG LongType: returning '4' as column: ANIMAL1_1_
10:44:18,578 DEBUG Loader: found row of collection: [org.lds.stack.petstore.model.Animal.countries#4]
10:44:18,578 DEBUG CollectionLoadContext: reading row
10:44:18,578 DEBUG LongType: returning '225' as column: COUNTRY2_1_
10:44:18,578 DEBUG DefaultLoadEventListener: loading entity: [org.lds.stack.petstore.model.Country#225]
10:44:18,578 DEBUG DefaultLoadEventListener: attempting to resolve: [org.lds.stack.petstore.model.Country#225]
10:44:18,578 DEBUG DefaultLoadEventListener: resolved object in session cache: [org.lds.stack.petstore.model.Country#225]
10:44:18,578 DEBUG Loader: result set row: 127
10:44:18,578 DEBUG LongType: returning '225' as column: id3_0_
10:44:18,578 DEBUG Loader: result row: EntityKey[org.lds.stack.petstore.model.Country#225]
10:44:18,578 DEBUG LongType: returning '3' as column: ANIMAL1_1_
10:44:18,578 DEBUG Loader: found row of collection: [org.lds.stack.petstore.model.Animal.countries#3]
10:44:18,578 DEBUG CollectionLoadContext: reading row
10:44:18,578 DEBUG LongType: returning '225' as column: COUNTRY2_1_
10:44:18,578 DEBUG DefaultLoadEventListener: loading entity: [org.lds.stack.petstore.model.Country#225]
10:44:18,578 DEBUG DefaultLoadEventListener: attempting to resolve: [org.lds.stack.petstore.model.Country#225]
10:44:18,578 DEBUG DefaultLoadEventListener: resolved object in session cache: [org.lds.stack.petstore.model.Country#225]
10:44:18,578 DEBUG Loader: result set row: 128
10:44:18,578 DEBUG LongType: returning '225' as column: id3_0_
10:44:18,578 DEBUG Loader: result row: EntityKey[org.lds.stack.petstore.model.Country#225]
10:44:18,578 DEBUG LongType: returning '2' as column: ANIMAL1_1_
10:44:18,578 DEBUG Loader: found row of collection: [org.lds.stack.petstore.model.Animal.countries#2]
10:44:18,578 DEBUG CollectionLoadContext: reading row
10:44:18,578 DEBUG LongType: returning '225' as column: COUNTRY2_1_
10:44:18,578 DEBUG DefaultLoadEventListener: loading entity: [org.lds.stack.petstore.model.Country#225]
10:44:18,578 DEBUG DefaultLoadEventListener: attempting to resolve: [org.lds.stack.petstore.model.Country#225]
10:44:18,578 DEBUG DefaultLoadEventListener: resolved object in session cache: [org.lds.stack.petstore.model.Country#225]
10:44:18,578 DEBUG Loader: done processing result set (129 rows)
10:44:18,578 DEBUG AbstractBatcher: about to close ResultSet (open ResultSets: 1, globally: 1)
10:44:18,578 DEBUG AbstractBatcher: about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
10:44:18,578 DEBUG AbstractBatcher: closing statement
10:44:18,578 DEBUG ConnectionManager: aggressively releasing JDBC connection
10:44:18,578 DEBUG ConnectionManager: releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
10:44:18,578 DEBUG Loader: total objects hydrated: 37
10:44:18,578 DEBUG TwoPhaseLoad: resolving associations for [org.lds.stack.petstore.model.Country#1]
10:44:18,578 DEBUG CollectionLoadContext: creating collection wrapper:[org.lds.stack.petstore.model.Country.animals#1]
10:44:18,578 DEBUG TwoPhaseLoad: adding entity to second-level cache: [org.lds.stack.petstore.model.Country#1]
10:44:18,578 DEBUG ReadOnlyCache: item already cached: org.lds.stack.petstore.model.Country#1
10:44:18,578 DEBUG TwoPhaseLoad: done materializing entity [org.lds.stack.petstore.model.Country#1]
10:44:18,578 DEBUG TwoPhaseLoad: resolving associations for [org.lds.stack.petstore.model.Country#2]
10:44:18,578 DEBUG CollectionLoadContext: creating collection wrapper:[org.lds.stack.petstore.model.Country.animals#2]
10:44:18,578 DEBUG TwoPhaseLoad: adding entity to second-level cache: [org.lds.stack.petstore.model.Country#2]
10:44:18,578 DEBUG ReadOnlyCache: item already cached: org.lds.stack.petstore.model.Country#2
10:44:18,578 DEBUG TwoPhaseLoad: done materializing entity [org.lds.stack.petstore.model.Country#2]
10:44:18,578 DEBUG TwoPhaseLoad: resolving associations for [org.lds.stack.petstore.model.Country#4]
10:44:18,578 DEBUG CollectionLoadContext: creating collection wrapper:[org.lds.stack.petstore.model.Country.animals#4]
10:44:18,578 DEBUG TwoPhaseLoad: adding entity to second-level cache: [org.lds.stack.petstore.model.Country#4]
10:44:18,578 DEBUG ReadOnlyCache: item already cached: org.lds.stack.petstore.model.Country#4
10:44:18,578 DEBUG TwoPhaseLoad: done materializing entity [org.lds.stack.petstore.model.Country#4]
10:44:18,593 DEBUG TwoPhaseLoad: resolving associations for [org.lds.stack.petstore.model.Country#7]
10:44:18,593 DEBUG CollectionLoadContext: creating collection wrapper:[org.lds.stack.petstore.model.Country.animals#7]
10:44:18,593 DEBUG TwoPhaseLoad: adding entity to second-level cache: [org.lds.stack.petstore.model.Country#7]
10:44:18,593 DEBUG ReadOnlyCache: item already cached: org.lds.stack.petstore.model.Country#7
10:44:18,593 DEBUG TwoPhaseLoad: done materializing entity [org.lds.stack.petstore.model.Country#7]
10:44:18,593 DEBUG TwoPhaseLoad: resolving associations for [org.lds.stack.petstore.model.Country#8]
10:44:18,593 DEBUG CollectionLoadContext: creating collection wrapper:[org.lds.stack.petstore.model.Country.animals#8]
10:44:18,593 DEBUG TwoPhaseLoad: adding entity to second-level cache: [org.lds.stack.petstore.model.Country#8]
10:44:18,593 DEBUG ReadOnlyCache: item already cached: org.lds.stack.petstore.model.Country#8
10:44:18,593 DEBUG TwoPhaseLoad: done materializing entity [org.lds.stack.petstore.model.Country#8]
10:44:18,593 DEBUG TwoPhaseLoad: resolving associations for [org.lds.stack.petstore.model.Country#9]
10:44:18,593 DEBUG CollectionLoadContext: creating collection wrapper:[org.lds.stack.petstore.model.Country.animals#9]
10:44:18,593 DEBUG TwoPhaseLoad: adding entity to second-level cache: [org.lds.stack.petstore.model.Country#9]
10:44:18,593 DEBUG ReadOnlyCache: item already cached: org.lds.stack.petstore.model.Country#9
10:44:18,593 DEBUG TwoPhaseLoad: done materializing entity [org.lds.stack.petstore.model.Country#9]
10:44:18,593 DEBUG TwoPhaseLoad: resolving associations for [org.lds.stack.petstore.model.Country#10]
10:44:18,593 DEBUG CollectionLoadContext: creating collection wrapper:[org.lds.stack.petstore.model.Country.animals#10]
10:44:18,593 DEBUG TwoPhaseLoad: adding entity to second-level cache: [org.lds.stack.petstore.model.Country#10]
10:44:18,593 DEBUG ReadOnlyCache: item already cached: org.lds.stack.petstore.model.Country#10
10:44:18,593 DEBUG TwoPhaseLoad: done materializing entity [org.lds.stack.petstore.model.Country#10]
10:44:18,593 DEBUG TwoPhaseLoad: resolving associations for [org.lds.stack.petstore.model.Country#12]
10:44:18,593 DEBUG CollectionLoadContext: creating collection wrapper:[org.lds.stack.petstore.model.Country.animals#12]
10:44:18,593 DEBUG TwoPhaseLoad: adding entity to second-level cache: [org.lds.stack.petstore.model.Country#12]
10:44:18,593 DEBUG ReadOnlyCache: item already cached: org.lds.stack.petstore.model.Country#12
10:44:18,593 DEBUG TwoPhaseLoad: done materializing entity [org.lds.stack.petstore.model.Country#12]
10:44:18,593 DEBUG TwoPhaseLoad: resolving associations for [org.lds.stack.petstore.model.Country#15]
10:44:18,593 DEBUG CollectionLoadContext: creating collection wrapper:[org.lds.stack.petstore.model.Country.animals#15]
10:44:18,593 DEBUG TwoPhaseLoad: adding entity to second-level cache: [org.lds.stack.petstore.model.Country#15]
10:44:18,593 DEBUG ReadOnlyCache: item already cached: org.lds.stack.petstore.model.Country#15
10:44:18,593 DEBUG TwoPhaseLoad: done materializing entity [org.lds.stack.petstore.model.Country#15]
10:44:18,593 DEBUG TwoPhaseLoad: resolving associations for [org.lds.stack.petstore.model.Country#16]
10:44:18,593 DEBUG CollectionLoadContext: creating collection wrapper:[org.lds.stack.petstore.model.Country.animals#16]
10:44:18,593 DEBUG TwoPhaseLoad: adding entity to second-level cache: [org.lds.stack.petstore.model.Country#16]
10:44:18,593 DEBUG ReadOnlyCache: item already cached: org.lds.stack.petstore.model.Country#16
10:44:18,593 DEBUG TwoPhaseLoad: done materializing entity [org.lds.stack.petstore.model.Country#16]
10:44:18,593 DEBUG TwoPhaseLoad: resolving associations for [org.lds.stack.petstore.model.Country#17]
10:44:18,593 DEBUG CollectionLoadContext: creating collection wrapper:[org.lds.stack.petstore.model.Country.animals#17]
10:44:18,593 DEBUG TwoPhaseLoad: adding entity to second-level cache: [org.lds.stack.petstore.model.Country#17]
10:44:18,593 DEBUG ReadOnlyCache: item already cached: org.lds.stack.petstore.model.Country#17
10:44:18,593 DEBUG TwoPhaseLoad: done materializing entity [org.lds.stack.petstore.model.Country#17]
10:44:18,593 DEBUG TwoPhaseLoad: resolving associations for [org.lds.stack.petstore.model.Country#22]
10:44:18,593 DEBUG CollectionLoadContext: creating collection wrapper:[org.lds.stack.petstore.model.Country.animals#22]
10:44:18,593 DEBUG TwoPhaseLoad: adding entity to second-level cache: [org.lds.stack.petstore.model.Country#22]
10:44:18,593 DEBUG ReadOnlyCache: item already cached: org.lds.stack.petstore.model.Country#22
10:44:18,593 DEBUG TwoPhaseLoad: done materializing entity [org.lds.stack.petstore.model.Country#22]
10:44:18,593 DEBUG TwoPhaseLoad: resolving associations for [org.lds.stack.petstore.model.Country#27]
10:44:18,593 DEBUG CollectionLoadContext: creating collection wrapper:[org.lds.stack.petstore.model.Country.animals#27]
10:44:18,593 DEBUG TwoPhaseLoad: adding entity to second-level cache: [org.lds.stack.petstore.model.Country#27]
10:44:18,593 DEBUG ReadOnlyCache: item already cached: org.lds.stack.petstore.model.Country#27
10:44:18,593 DEBUG TwoPhaseLoad: done materializing entity [org.lds.stack.petstore.model.Country#27]
10:44:18,593 DEBUG TwoPhaseLoad: resolving associations for [org.lds.stack.petstore.model.Country#29]
10:44:18,593 DEBUG CollectionLoadContext: creating collection wrapper:[org.lds.stack.petstore.model.Country.animals#29]
10:44:18,593 DEBUG TwoPhaseLoad: adding entity to second-level cache: [org.lds.stack.petstore.model.Country#29]
10:44:18,593 DEBUG ReadOnlyCache: item already cached: org.lds.stack.petstore.model.Country#29
10:44:18,593 DEBUG TwoPhaseLoad: done materializing entity [org.lds.stack.petstore.model.Country#29]
10:44:18,593 DEBUG TwoPhaseLoad: resolving associations for [org.lds.stack.petstore.model.Country#33]
10:44:18,593 DEBUG CollectionLoadContext: creating collection wrapper:[org.lds.stack.petstore.model.Country.animals#33]
10:44:18,593 DEBUG TwoPhaseLoad: adding entity to second-level cache: [org.lds.stack.petstore.model.Country#33]
10:44:18,593 DEBUG ReadOnlyCache: item already cached: org.lds.stack.petstore.model.Country#33
10:44:18,593 DEBUG TwoPhaseLoad: done materializing entity [org.lds.stack.petstore.model.Country#33]
10:44:18,593 DEBUG TwoPhaseLoad: resolving associations for [org.lds.stack.petstore.model.Country#38]
10:44:18,593 DEBUG CollectionLoadContext: creating collection wrapper:[org.lds.stack.petstore.model.Country.animals#38]
10:44:18,593 DEBUG TwoPhaseLoad: adding entity to second-level cache: [org.lds.stack.petstore.model.Country#38]
10:44:18,593 DEBUG ReadOnlyCache: item already cached: org.lds.stack.petstore.model.Country#38
10:44:18,593 DEBUG TwoPhaseLoad: done materializing entity [org.lds.stack.petstore.model.Country#38]
10:44:18,593 DEBUG TwoPhaseLoad: resolving associations for [org.lds.stack.petstore.model.Country#40]
10:44:18,593 DEBUG CollectionLoadContext: creating collection wrapper:[org.lds.stack.petstore.model.Country.animals#40]
10:44:18,593 DEBUG TwoPhaseLoad: adding entity to second-level cache: [org.lds.stack.petstore.model.Country#40]
10:44:18,593 DEBUG ReadOnlyCache: item already cached: org.lds.stack.petstore.model.Country#40
10:44:18,593 DEBUG TwoPhaseLoad: done materializing entity [org.lds.stack.petstore.model.Country#40]
10:44:18,593 DEBUG TwoPhaseLoad: resolving associations for [org.lds.stack.petstore.model.Country#41]
10:44:18,593 DEBUG CollectionLoadContext: creating collection wrapper:[org.lds.stack.petstore.model.Country.animals#41]
10:44:18,593 DEBUG TwoPhaseLoad: adding entity to second-level cache: [org.lds.stack.petstore.model.Country#41]
10:44:18,593 DEBUG ReadOnlyCache: item already cached: org.lds.stack.petstore.model.Country#41
10:44:18,593 DEBUG TwoPhaseLoad: done materializing entity [org.lds.stack.petstore.model.Country#41]
10:44:18,593 DEBUG TwoPhaseLoad: resolving associations for [org.lds.stack.petstore.model.Country#44]
10:44:18,593 DEBUG CollectionLoadContext: creating collection wrapper:[org.lds.stack.petstore.model.Country.animals#44]
10:44:18,593 DEBUG TwoPhaseLoad: adding entity to second-level cache: [org.lds.stack.petstore.model.Country#44]
10:44:18,593 DEBUG ReadOnlyCache: item already cached: org.lds.stack.petstore.model.Country#44
10:44:18,593 DEBUG TwoPhaseLoad: done materializing entity [org.lds.stack.petstore.model.Country#44]
10:44:18,593 DEBUG TwoPhaseLoad: resolving associations for [org.lds.stack.petstore.model.Country#45]
10:44:18,593 DEBUG CollectionLoadContext: creating collection wrapper:[org.lds.stack.petstore.model.Country.animals#45]
10:44:18,593 DEBUG TwoPhaseLoad: adding entity to second-level cache: [org.lds.stack.petstore.model.Country#45]
10:44:18,593 DEBUG ReadOnlyCache: item already cached: org.lds.stack.petstore.model.Country#45
10:44:18,593 DEBUG TwoPhaseLoad: done materializing entity [org.lds.stack.petstore.model.Country#45]
10:44:18,593 DEBUG TwoPhaseLoad: resolving associations for [org.lds.stack.petstore.model.Country#46]
10:44:18,593 DEBUG CollectionLoadContext: creating collection wrapper:[org.lds.stack.petstore.model.Country.animals#46]
10:44:18,593 DEBUG TwoPhaseLoad: adding entity to second-level cache: [org.lds.stack.petstore.model.Country#46]
10:44:18,593 DEBUG ReadOnlyCache: item already cached: org.lds.stack.petstore.model.Country#46
10:44:18,593 DEBUG TwoPhaseLoad: done materializing entity [org.lds.stack.petstore.model.Country#46]
10:44:18,593 DEBUG TwoPhaseLoad: resolving associations for [org.lds.stack.petstore.model.Country#47]
10:44:18,593 DEBUG CollectionLoadContext: creating collection wrapper:[org.lds.stack.petstore.model.Country.animals#47]
10:44:18,593 DEBUG TwoPhaseLoad: adding entity to second-level cache: [org.lds.stack.petstore.model.Country#47]
10:44:18,593 DEBUG ReadOnlyCache: item already cached: org.lds.stack.petstore.model.Country#47
10:44:18,593 DEBUG TwoPhaseLoad: done materializing entity [org.lds.stack.petstore.model.Country#47]
10:44:18,593 DEBUG TwoPhaseLoad: resolving associations for [org.lds.stack.petstore.model.Country#60]
10:44:18,593 DEBUG CollectionLoadContext: creating collection wrapper:[org.lds.stack.petstore.model.Country.animals#60]
10:44:18,593 DEBUG TwoPhaseLoad: adding entity to second-level cache: [org.lds.stack.petstore.model.Country#60]
10:44:18,593 DEBUG ReadOnlyCache: item already cached: org.lds.stack.petstore.model.Country#60
10:44:18,593 DEBUG TwoPhaseLoad: done materializing entity [org.lds.stack.petstore.model.Country#60]
10:44:18,593 DEBUG TwoPhaseLoad: resolving associations for [org.lds.stack.petstore.model.Country#63]
10:44:18,593 DEBUG CollectionLoadContext: creating collection wrapper:[org.lds.stack.petstore.model.Country.animals#63]
10:44:18,593 DEBUG TwoPhaseLoad: adding entity to second-level cache: [org.lds.stack.petstore.model.Country#63]
10:44:18,593 DEBUG ReadOnlyCache: item already cached: org.lds.stack.petstore.model.Country#63
10:44:18,593 DEBUG TwoPhaseLoad: done materializing entity [org.lds.stack.petstore.model.Country#63]
10:44:18,593 DEBUG TwoPhaseLoad: resolving associations for [org.lds.stack.petstore.model.Country#67]
10:44:18,593 DEBUG CollectionLoadContext: creating collection wrapper:[org.lds.stack.petstore.model.Country.animals#67]
10:44:18,593 DEBUG TwoPhaseLoad: adding entity to second-level cache: [org.lds.stack.petstore.model.Country#67]
10:44:18,593 DEBUG ReadOnlyCache: item already cached: org.lds.stack.petstore.model.Country#67
10:44:18,593 DEBUG TwoPhaseLoad: done materializing entity [org.lds.stack.petstore.model.Country#67]
10:44:18,593 DEBUG TwoPhaseLoad: resolving associations for [org.lds.stack.petstore.model.Country#77]
10:44:18,593 DEBUG CollectionLoadContext: creating collection wrapper:[org.lds.stack.petstore.model.Country.animals#77]
10:44:18,593 DEBUG TwoPhaseLoad: adding entity to second-level cache: [org.lds.stack.petstore.model.Country#77]
10:44:18,593 DEBUG ReadOnlyCache: item already cached: org.lds.stack.petstore.model.Country#77
10:44:18,593 DEBUG TwoPhaseLoad: done materializing entity [org.lds.stack.petstore.model.Country#77]
10:44:18,593 DEBUG TwoPhaseLoad: resolving associations for [org.lds.stack.petstore.model.Country#88]
10:44:18,593 DEBUG CollectionLoadContext: creating collection wrapper:[org.lds.stack.petstore.model.Country.animals#88]
10:44:18,593 DEBUG TwoPhaseLoad: adding entity to second-level cache: [org.lds.stack.petstore.model.Country#88]
10:44:18,593 DEBUG ReadOnlyCache: item already cached: org.lds.stack.petstore.model.Country#88
10:44:18,593 DEBUG TwoPhaseLoad: done materializing entity [org.lds.stack.petstore.model.Country#88]
10:44:18,593 DEBUG TwoPhaseLoad: resolving associations for [org.lds.stack.petstore.model.Country#90]
10:44:18,593 DEBUG CollectionLoadContext: creating collection wrapper:[org.lds.stack.petstore.model.Country.animals#90]
10:44:18,593 DEBUG TwoPhaseLoad: adding entity to second-level cache: [org.lds.stack.petstore.model.Country#90]
10:44:18,593 DEBUG ReadOnlyCache: item already cached: org.lds.stack.petstore.model.Country#90
10:44:18,593 DEBUG TwoPhaseLoad: done materializing entity [org.lds.stack.petstore.model.Country#90]
10:44:18,593 DEBUG TwoPhaseLoad: resolving associations for [org.lds.stack.petstore.model.Country#91]
10:44:18,593 DEBUG CollectionLoadContext: creating collection wrapper:[org.lds.stack.petstore.model.Country.animals#91]
10:44:18,593 DEBUG TwoPhaseLoad: adding entity to second-level cache: [org.lds.stack.petstore.model.Country#91]
10:44:18,593 DEBUG ReadOnlyCache: item already cached: org.lds.stack.petstore.model.Country#91
10:44:18,593 DEBUG TwoPhaseLoad: done materializing entity [org.lds.stack.petstore.model.Country#91]
10:44:18,593 DEBUG TwoPhaseLoad: resolving associations for [org.lds.stack.petstore.model.Country#98]
10:44:18,593 DEBUG CollectionLoadContext: creating collection wrapper:[org.lds.stack.petstore.model.Country.animals#98]
10:44:18,593 DEBUG TwoPhaseLoad: adding entity to second-level cache: [org.lds.stack.petstore.model.Country#98]
10:44:18,593 DEBUG ReadOnlyCache: item already cached: org.lds.stack.petstore.model.Country#98
10:44:18,593 DEBUG TwoPhaseLoad: done materializing entity [org.lds.stack.petstore.model.Country#98]
10:44:18,593 DEBUG TwoPhaseLoad: resolving associations for [org.lds.stack.petstore.model.Country#99]
10:44:18,593 DEBUG CollectionLoadContext: creating collection wrapper:[org.lds.stack.petstore.model.Country.animals#99]
10:44:18,593 DEBUG TwoPhaseLoad: adding entity to second-level cache: [org.lds.stack.petstore.model.Country#99]
10:44:18,593 DEBUG ReadOnlyCache: item already cached: org.lds.stack.petstore.model.Country#99
10:44:18,593 DEBUG TwoPhaseLoad: done materializing entity [org.lds.stack.petstore.model.Country#99]
10:44:18,593 DEBUG TwoPhaseLoad: resolving associations for [org.lds.stack.petstore.model.Country#100]
10:44:18,593 DEBUG CollectionLoadContext: creating collection wrapper:[org.lds.stack.petstore.model.Country.animals#100]
10:44:18,593 DEBUG TwoPhaseLoad: adding entity to second-level cache: [org.lds.stack.petstore.model.Country#100]
10:44:18,593 DEBUG ReadOnlyCache: item already cached: org.lds.stack.petstore.model.Country#100
10:44:18,593 DEBUG TwoPhaseLoad: done materializing entity [org.lds.stack.petstore.model.Country#100]
10:44:18,593 DEBUG TwoPhaseLoad: resolving associations for [org.lds.stack.petstore.model.Country#139]
10:44:18,593 DEBUG CollectionLoadContext: creating collection wrapper:[org.lds.stack.petstore.model.Country.animals#139]
10:44:18,593 DEBUG TwoPhaseLoad: adding entity to second-level cache: [org.lds.stack.petstore.model.Country#139]
10:44:18,593 DEBUG ReadOnlyCache: item already cached: org.lds.stack.petstore.model.Country#139
10:44:18,593 DEBUG TwoPhaseLoad: done materializing entity [org.lds.stack.petstore.model.Country#139]
10:44:18,593 DEBUG TwoPhaseLoad: resolving associations for [org.lds.stack.petstore.model.Country#150]
10:44:18,593 DEBUG CollectionLoadContext: creating collection wrapper:[org.lds.stack.petstore.model.Country.animals#150]
10:44:18,593 DEBUG TwoPhaseLoad: adding entity to second-level cache: [org.lds.stack.petstore.model.Country#150]
10:44:18,593 DEBUG ReadOnlyCache: item already cached: org.lds.stack.petstore.model.Country#150
10:44:18,593 DEBUG TwoPhaseLoad: done materializing entity [org.lds.stack.petstore.model.Country#150]
10:44:18,593 DEBUG TwoPhaseLoad: resolving associations for [org.lds.stack.petstore.model.Country#214]
10:44:18,593 DEBUG CollectionLoadContext: creating collection wrapper:[org.lds.stack.petstore.model.Country.animals#214]
10:44:18,593 DEBUG TwoPhaseLoad: adding entity to second-level cache: [org.lds.stack.petstore.model.Country#214]
10:44:18,593 DEBUG ReadOnlyCache: item already cached: org.lds.stack.petstore.model.Country#214
10:44:18,593 DEBUG TwoPhaseLoad: done materializing entity [org.lds.stack.petstore.model.Country#214]
10:44:18,593 DEBUG TwoPhaseLoad: resolving associations for [org.lds.stack.petstore.model.Country#224]
10:44:18,593 DEBUG CollectionLoadContext: creating collection wrapper:[org.lds.stack.petstore.model.Country.animals#224]
10:44:18,593 DEBUG TwoPhaseLoad: adding entity to second-level cache: [org.lds.stack.petstore.model.Country#224]
10:44:18,593 DEBUG ReadOnlyCache: item already cached: org.lds.stack.petstore.model.Country#224
10:44:18,593 DEBUG TwoPhaseLoad: done materializing entity [org.lds.stack.petstore.model.Country#224]
10:44:18,593 DEBUG TwoPhaseLoad: resolving associations for [org.lds.stack.petstore.model.Country#225]
10:44:18,593 DEBUG CollectionLoadContext: creating collection wrapper:[org.lds.stack.petstore.model.Country.animals#225]
10:44:18,593 DEBUG TwoPhaseLoad: adding entity to second-level cache: [org.lds.stack.petstore.model.Country#225]
10:44:18,593 DEBUG ReadOnlyCache: item already cached: org.lds.stack.petstore.model.Country#225
10:44:18,593 DEBUG TwoPhaseLoad: done materializing entity [org.lds.stack.petstore.model.Country#225]
10:44:18,593 DEBUG CollectionLoadContext: 56 collections were found in result set for role: org.lds.stack.petstore.model.Animal.countries
10:44:18,593 DEBUG CollectionLoadContext: Caching collection: [org.lds.stack.petstore.model.Animal.countries#46]
10:44:18,593 DEBUG CacheSynchronization: transaction after completion callback, status: 4
10:44:18,593 DEBUG JDBCContext: after transaction completion
10:44:18,593 DEBUG SessionImpl: after transaction completion
10:44:18,593 DEBUG JDBCContext: TransactionFactory reported no active transaction; Synchronization not registered
10:44:18,593 DEBUG JDBCContext: TransactionFactory reported no active transaction; Synchronization not registered
10:44:18,593 DEBUG JDBCContext: TransactionFactory reported no active transaction; Synchronization not registered
10:44:18,593 DEBUG JDBCContext: TransactionFactory reported no active transaction; Synchronization not registered
Jan 29, 2007 10:44:18 AM com.sun.facelets.FaceletViewHandler handleRenderException
SEVERE: Error Rendering View[/pet-search.xhtml]
javax.faces.FacesException: javax.el.ELException: /pet-search.xhtml @59,97 rendered="#{empty petSearchBean.currentResults}": java.lang.NullPointerException
at javax.faces.component.UIComponentBase.isRendered(UIComponentBase.java:387)
at javax.faces.component.UIComponent.encodeAll(UIComponent.java:878)
at javax.faces.component.UIComponent.encodeAll(UIComponent.java:890)
at com.sun.facelets.FaceletViewHandler.renderView(FaceletViewHandler.java:571)
at org.ajax4jsf.framework.ViewHandlerWrapper.renderView(ViewHandlerWrapper.java:101)
at org.ajax4jsf.framework.ajax.AjaxViewHandler.renderView(AjaxViewHandler.java:222)
at com.sun.faces.lifecycle.RenderResponsePhase.execute(RenderResponsePhase.java:106)
at com.sun.faces.lifecycle.LifecycleImpl.phase(LifecycleImpl.java:248)
at com.sun.faces.lifecycle.LifecycleImpl.render(LifecycleImpl.java:144)
at javax.faces.webapp.FacesServlet.service(FacesServlet.java:245)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:252)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:173)
at org.ajax4jsf.framework.ajax.xmlfilter.BaseXMLFilter.doXmlFilter(BaseXMLFilter.java:75)
at org.ajax4jsf.framework.ajax.xmlfilter.BaseFilter.doFilter(BaseFilter.java:213)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:202)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:173)
at org.apache.myfaces.webapp.filter.ExtensionsFilter.doFilter(ExtensionsFilter.java:144)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:202)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:173)
at org.springframework.orm.jpa.support.OpenEntityManagerInViewFilter.doFilterInternal(OpenEntityManagerInViewFilter.java:112)
at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:77)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:202)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:173)
at org.acegisecurity.util.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:264)
at org.acegisecurity.intercept.web.FilterSecurityInterceptor.invoke(FilterSecurityInterceptor.java:107)
at org.acegisecurity.intercept.web.FilterSecurityInterceptor.doFilter(FilterSecurityInterceptor.java:72)
at org.acegisecurity.util.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:274)
at org.acegisecurity.ui.ExceptionTranslationFilter.doFilter(ExceptionTranslationFilter.java:110)
at org.acegisecurity.util.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:274)
at org.acegisecurity.providers.anonymous.AnonymousProcessingFilter.doFilter(AnonymousProcessingFilter.java:125)
at org.acegisecurity.util.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:274)
at org.acegisecurity.wrapper.SecurityContextHolderAwareRequestFilter.doFilter(SecurityContextHolderAwareRequestFilter.java:81)
at org.acegisecurity.util.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:274)
at org.acegisecurity.ui.AbstractProcessingFilter.doFilter(AbstractProcessingFilter.java:217)
at org.acegisecurity.util.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:274)
at org.acegisecurity.ui.logout.LogoutFilter.doFilter(LogoutFilter.java:106)
at org.acegisecurity.util.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:274)
at org.acegisecurity.context.HttpSessionContextIntegrationFilter.doFilter(HttpSessionContextIntegrationFilter.java:229)
at org.acegisecurity.util.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:274)
at org.acegisecurity.util.FilterChainProxy.doFilter(FilterChainProxy.java:148)
at org.acegisecurity.util.FilterToBeanProxy.doFilter(FilterToBeanProxy.java:98)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:202)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:173)
at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:213)
at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:178)
at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:432)
at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:126)
at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:105)
at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:107)
at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:148)
at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:869)
at org.apache.coyote.http11.Http11BaseProtocol$Http11ConnectionHandler.processConnection(Http11BaseProtocol.java:664)
at org.apache.tomcat.util.net.PoolTcpEndpoint.processSocket(PoolTcpEndpoint.java:527)
at org.apache.tomcat.util.net.LeaderFollowerWorkerThread.runIt(LeaderFollowerWorkerThread.java:80)
at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.java:684)
at java.lang.Thread.run(Thread.java:595)
Caused by: javax.el.ELException: /pet-search.xhtml @59,97 rendered="#{empty petSearchBean.currentResults}": java.lang.NullPointerException
at com.sun.facelets.el.TagValueExpression.getValue(TagValueExpression.java:76)
at javax.faces.component.UIComponentBase.isRendered(UIComponentBase.java:384)
... 55 more
Caused by: java.lang.NullPointerException
at org.hibernate.engine.CollectionLoadContext.addCollectionToCache(CollectionLoadContext.java:306)
at org.hibernate.engine.CollectionLoadContext.endLoadingCollection(CollectionLoadContext.java:203)
at org.hibernate.engine.CollectionLoadContext.endLoadingCollections(CollectionLoadContext.java:268)
at org.hibernate.engine.CollectionLoadContext.endLoadingCollections(CollectionLoadContext.java:249)
at org.hibernate.loader.Loader.endCollectionLoad(Loader.java:866)
at org.hibernate.loader.Loader.initializeEntitiesAndCollections(Loader.java:853)
at org.hibernate.loader.Loader.doQuery(Loader.java:717)
at org.hibernate.loader.Loader.doQueryAndInitializeNonLazyCollections(Loader.java:224)
at org.hibernate.loader.Loader.loadCollectionSubselect(Loader.java:2057)
at org.hibernate.loader.collection.SubselectCollectionLoader.initialize(SubselectCollectionLoader.java:58)
at org.hibernate.persister.collection.AbstractCollectionPersister.initialize(AbstractCollectionPersister.java:565)
at org.hibernate.event.def.DefaultInitializeCollectionEventListener.onInitializeCollection(DefaultInitializeCollectionEventListener.java:60)
at org.hibernate.impl.SessionImpl.initializeCollection(SessionImpl.java:1716)
at org.hibernate.collection.AbstractPersistentCollection.forceInitialization(AbstractPersistentCollection.java:454)
at org.hibernate.engine.StatefulPersistenceContext.initializeNonLazyCollections(StatefulPersistenceContext.java:784)
at org.hibernate.loader.Loader.doQueryAndInitializeNonLazyCollections(Loader.java:229)
at org.hibernate.loader.Loader.doList(Loader.java:2211)
at org.hibernate.loader.Loader.listIgnoreQueryCache(Loader.java:2095)
at org.hibernate.loader.Loader.list(Loader.java:2090)
at org.hibernate.loader.hql.QueryLoader.list(QueryLoader.java:375)
at org.hibernate.hql.ast.QueryTranslatorImpl.list(QueryTranslatorImpl.java:338)
at org.hibernate.engine.query.HQLQueryPlan.performList(HQLQueryPlan.java:172)
at org.hibernate.impl.SessionImpl.list(SessionImpl.java:1121)
at org.hibernate.impl.QueryImpl.list(QueryImpl.java:79)
at org.hibernate.ejb.QueryImpl.getResultList(QueryImpl.java:64)
at org.lds.stack.serviceproxy.jpa.hibernate.AbstractQueryFindExecutor.executeQuery(AbstractQueryFindExecutor.java:44)
at org.lds.stack.serviceproxy.jpa.FindInterceptor$1.doInJpa(FindInterceptor.java:43)
at org.springframework.orm.jpa.JpaTemplate.execute(JpaTemplate.java:191)
at org.springframework.orm.jpa.JpaTemplate.execute(JpaTemplate.java:154)
at org.lds.stack.serviceproxy.jpa.FindInterceptor.invoke(FindInterceptor.java:39)
at org.lds.stack.serviceproxy.ServiceProxyCglibInterceptor.intercept(ServiceProxyCglibInterceptor.java:48)
at org.lds.stack.petstore.service.AbstractAnimalService$$EnhancerByCGLIB$$3d59b0a4.searchForAnimals(<generated>)
at org.lds.stack.petstore.service.AnimalService$$FastClassByCGLIB$$5fa987b7.invoke(<generated>)
at net.sf.cglib.proxy.MethodProxy.invoke(MethodProxy.java:163)
at org.springframework.aop.framework.Cglib2AopProxy$CglibMethodInvocation.invokeJoinpoint(Cglib2AopProxy.java:675)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:154)
at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:107)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:176)
at org.springframework.aop.framework.Cglib2AopProxy$DynamicAdvisedInterceptor.intercept(Cglib2AopProxy.java:616)
at org.lds.stack.petstore.service.AbstractAnimalService$$EnhancerByCGLIB$$74b4a0c2.searchForAnimals(<generated>)
at org.lds.stack.petstore.view.bean.PetSearchBean.getCurrentResults(PetSearchBean.java:39)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:585)
at javax.el.BeanELResolver.getValue(BeanELResolver.java:218)
at javax.el.CompositeELResolver.getValue(CompositeELResolver.java:135)
at com.sun.faces.el.FacesCompositeELResolver.getValue(FacesCompositeELResolver.java:64)
at com.sun.el.parser.AstValue.getValue(AstValue.java:118)
at com.sun.el.parser.AstEmpty.getValue(AstEmpty.java:49)
at com.sun.el.ValueExpressionImpl.getValue(ValueExpressionImpl.java:192)
at com.sun.facelets.el.TagValueExpression.getValue(TagValueExpression.java:71)
... 56 more
--
This message is automatically generated by JIRA.
-
If you think it was sent incorrectly contact one of the administrators:
http://opensource.atlassian.com/projects/hibernate/secure/Administrators....
-
For more information on JIRA, see:
http://www.atlassian.com/software/jira
15 years, 2 months
[Hibernate-JIRA] Created: (HHH-5019) @TableGenerator throws Unsupported exception - error performing isolated work
by Rohini (JIRA)
@TableGenerator throws Unsupported exception - error performing isolated work
-----------------------------------------------------------------------------
Key: HHH-5019
URL: http://opensource.atlassian.com/projects/hibernate/browse/HHH-5019
Project: Hibernate Core
Issue Type: Bug
Affects Versions: 3.3.1, 3.3.0.SP1, 3.3.0.GA, 3.3.0.CR2, 3.3.0.CR1, 3.2.7, 3.2.6, 3.2.5, 3.2.4.sp1, 3.2.4, 3.2.3, 3.2.2, 3.2.1
Environment: Hibernate Core 3.3.1, MySQL, Websphere 6.1 with EJB3.0 Feature pack
Reporter: Rohini
While implementing GenerationType.TABLE strategy with Hibernate as the persistence provider, id generation throws
javax.persistence.PersistenceException: org.hibernate.HibernateException: error performing isolated work
[3/18/10 14:40:41:533 IST] 0000002d SystemErr R at org.hibernate.ejb.AbstractEntityManagerImpl.throwPersistenceException(AbstractEntityManagerImpl.java:614)
--------------------------------------------------------------
3/18/10 14:40:41:533 IST] 0000002d SystemErr R Caused by: org.hibernate.HibernateException: error performing isolated work
at org.hibernate.engine.transaction.Isolater$JtaDelegate.delegateWork(Isolater.java:166)
at org.hibernate.engine.transaction.Isolater.doIsolatedWork(Isolater.java:64)
at org.hibernate.engine.TransactionHelper.doWorkInNewTransaction(TransactionHelper.java:74)
at org.hibernate.id.MultipleHiLoPerTableGenerator.generate(MultipleHiLoPerTableGenerator.java:210)
Looking at the
Isolater.doIsolatedWork( work, session );, implementation
try {
// First we need to suspend any current JTA transaction and obtain
// a JDBC connection
surroundingTransaction = transactionManager.suspend();
if ( log.isDebugEnabled() ) {
log.debug( "surrounding JTA transaction suspended [" + surroundingTransaction + "]" );
}
This happnes only with WebsphereExtendedTransactionManagerLookup as the hibernate.transaction.manager_lookup_class.
--
This message is automatically generated by JIRA.
-
If you think it was sent incorrectly contact one of the administrators: http://opensource.atlassian.com/projects/hibernate/secure/Administrators....
-
For more information on JIRA, see: http://www.atlassian.com/software/jira
15 years, 2 months
[Hibernate-JIRA] Created: (HHH-5057) ScrollableResults does not fetch many-to-many collections
by Jérôme Van Der Linden (JIRA)
ScrollableResults does not fetch many-to-many collections
---------------------------------------------------------
Key: HHH-5057
URL: http://opensource.atlassian.com/projects/hibernate/browse/HHH-5057
Project: Hibernate Core
Issue Type: Bug
Components: core
Affects Versions: 3.3.2
Reporter: Jérôme Van Der Linden
Priority: Blocker
I have a many-to-many relation between two objects :
{code:title=Project.java|borderStyle=solid}
@Entity
public class Project {
private List<Viperson> managers;
@ManyToMany(targetEntity = Viperson.class)
@JoinTable(name = "PRJMANAGER", joinColumns = @JoinColumn(name = "PROJECTID", nullable = false), inverseJoinColumns = @JoinColumn(name = "VIPID", nullable = false))
public List<Viperson> getManagers() {
return managers;
}
}
{code}
{code:title=Viperson.java|borderStyle=solid}
@Entity
public class Viperson {
private List<Project> projects;
@ManyToMany(mappedBy = "managers", targetEntity = Project.class)
public List<Project> getProjects() {
return projects;
}
}
{code}
And the following test (actually, it is a code from spring batch HibernateCursorItemReader I put in a testcase) :
{code}
@Test
public void testSelectAll() {
StatelessSession statelessSession = sessionFactory.openStatelessSession();
ScrollableResults cursor = statelessSession.createQuery("from Project").scroll();
Object[] data = null;
if (cursor.next()) {
data = cursor.get();
}
}
{code}
data contains a {{Project}} but {{managers}} field is *null*, +even if I add eager fetching+. I have also a {{OneToMany}} in the {{Project}} class. This one is well loaded (i have a {{PersistentBag}}).
Is there anything I miss ? I suspect a bug on that.
--
This message is automatically generated by JIRA.
-
If you think it was sent incorrectly contact one of the administrators: http://opensource.atlassian.com/projects/hibernate/secure/Administrators....
-
For more information on JIRA, see: http://www.atlassian.com/software/jira
15 years, 3 months
[Hibernate-JIRA] Created: (ANN-843) Version increment not triggered on @OneToOne property modification having inverse owner
by Guenther Demetz (JIRA)
Version increment not triggered on @OneToOne property modification having inverse owner
---------------------------------------------------------------------------------------
Key: ANN-843
URL: http://opensource.atlassian.com/projects/hibernate/browse/ANN-843
Project: Hibernate Annotations
Issue Type: Bug
Affects Versions: 3.4.0.GA
Environment: Hibernate 3.3.1.GA , Microsoft SQL Server
Reporter: Guenther Demetz
Priority: Minor
Attachments: Testcase.jar
In the revised "Java Persistence with Hibernate" book by Christian Bauer and Gavin King on page 464
there's written following about versioning:
"If you use Hibernate as JPA provider ... every value-typed property modification .. triggers a version increment."
Now I saw that Version increment indeed is not triggered on @OneToOne properties having an inverse owner (= mappedBy setted).
This allows several concurrent transactions to set the association from same object towards different targets without having a OptimistickLockException at commit.
This violates the ToOne policy! (Hibernate detects the inconsistency later when loading the property from database:
org.hibernate.HibernateException: More than one row with the given identifier was found)
Please see attached junit-testcase for reproducing the problem.
regards
Guenther Demetz
--
This message is automatically generated by JIRA.
-
If you think it was sent incorrectly contact one of the administrators: http://opensource.atlassian.com/projects/hibernate/secure/Administrators....
-
For more information on JIRA, see: http://www.atlassian.com/software/jira
15 years, 3 months
[Hibernate-JIRA] Created: (HHH-5163) ClassCastException when Hibernate tries to cache results using ResultTransformer
by Strong Liu (JIRA)
ClassCastException when Hibernate tries to cache results using ResultTransformer
--------------------------------------------------------------------------------
Key: HHH-5163
URL: http://opensource.atlassian.com/projects/hibernate/browse/HHH-5163
Project: Hibernate Core
Issue Type: Bug
Components: core
Affects Versions: 3.5.1
Reporter: Strong Liu
Assignee: Gail Badner
Fix For: 3.5.x, 3.6
When Hibernate executes a cacheable query using a ResultTransformer, it will attempt to cache the results AFTER applying the ResultTransformer. The problem is that the ResultTransformer may modify the data in a way that Hibernate won't understand it anymore, and in this case it will generate a ClassCastException when trying to cache it.
---------------------------
this can be reproduced by CriteriaQueryTest with following change:
papa-pc:testsuite stliu$ svn diff src/test/java/org/hibernate/test/criteria/CriteriaQueryTest.java
Index: src/test/java/org/hibernate/test/criteria/CriteriaQueryTest.java
===================================================================
--- src/test/java/org/hibernate/test/criteria/CriteriaQueryTest.java (revision 19246)
+++ src/test/java/org/hibernate/test/criteria/CriteriaQueryTest.java (working copy)
@@ -613,6 +613,7 @@
)
.addOrder( Order.desc("studentName") )
.setResultTransformer( Transformers.aliasToBean(StudentDTO.class) )
+ .setCacheable( true )
.list();
assertEquals(2, resultWithAliasedBean.size());
--
This message is automatically generated by JIRA.
-
If you think it was sent incorrectly contact one of the administrators: http://opensource.atlassian.com/projects/hibernate/secure/Administrators....
-
For more information on JIRA, see: http://www.atlassian.com/software/jira
15 years, 3 months
[Hibernate-JIRA] Created: (HHH-3872) Criteria on alias causes partial collection materialization
by Adrian Moos (JIRA)
Criteria on alias causes partial collection materialization
-----------------------------------------------------------
Key: HHH-3872
URL: http://opensource.atlassian.com/projects/hibernate/browse/HHH-3872
Project: Hibernate Core
Issue Type: Bug
Components: query-criteria
Affects Versions: 3.3.0.CR1
Reporter: Adrian Moos
I have a parent entity with a one-to-many assocation to a child entity:
<hibernate-mapping package="ch.bedag.a11.ccinfo.business.entity" default-lazy="false">
<class name="Parent" table="PARENT">
<id name="id" type="long" column="ID" unsaved-value="null">
<generator class="sequence">
<param name="sequence">SEQ_T_PARENT</param>
</generator>
</id>
<set name="children" cascade="all-delete-orphan" inverse="true">
<key column="PARENT_ID" foreign-key="CHILD_FK1"/>
<one-to-many class="Child"/>
</set>
</class>
<class name="Child"
<id name="id" type="long" column="ID" unsaved-value="null">
<generator class="sequence">
<param name="sequence">SEQ_T_CHILD</param>
</generator>
</id>
<property name="businessKey" column="BUSINESSKEY" not-null="true"/>
</class>
</hibernate-mapping>
I then do:
Criteria parentCriteria = aSession.createCriteria(Parent.class);
parentCriteria.createAlias("children", "c", CriteriaSpecification.LEFT_JOIN);
parentCriteria.setResultTransformer(CriteriaSpecification.DISTINCT_ROOT_ENTITY);
parentCriteria.add(Restrictions.eq("c.businessKey", 123456789));
List parents = parentCriteria.list();
Expected behaviour: Since each parent in parents is a materialized entity, I'd expect its children set to contain all its children.
Observed behaviour: It contains only children with matching business key.
Is my expectation correct?
--
This message is automatically generated by JIRA.
-
If you think it was sent incorrectly contact one of the administrators: http://opensource.atlassian.com/projects/hibernate/secure/Administrators....
-
For more information on JIRA, see: http://www.atlassian.com/software/jira
15 years, 3 months
[Hibernate-JIRA] Created: (HHH-3230) getEntityName() throws org.hibernate.TransientObjectException: proxy was not associated with the session
by Howard M. Lewis Ship (JIRA)
getEntityName() throws org.hibernate.TransientObjectException: proxy was not associated with the session
--------------------------------------------------------------------------------------------------------
Key: HHH-3230
URL: http://opensource.atlassian.com/projects/hibernate/browse/HHH-3230
Project: Hibernate3
Issue Type: Bug
Components: core
Affects Versions: 3.2.2
Environment: Mac OS X, JDK 1.5
Reporter: Howard M. Lewis Ship
I'm retrieving an entity that contains a OneToMany relationship.
The master entity is retrieved, within a transaction, via Session.get(Class,Serializable).
@Entity
public class MapUnitSurvey extends ActiveDO
{
@ManyToOne(fetch = FetchType.LAZY)
private VegetationType vegetationType;
}
@Entity
public class VegetationType extends AbstractEnum
{
}
ActiveDO and AbstractEnum are abstract base classes with @MappedSuperclass.
I retrieve the vegationType:
VegetationType type = survey.getVegetationType();
Then I need the type's entity name
String entityName = session.getEntityName(type);
This fails with the TransientObjectException.
Inspecting with the debugger, I see that type is a CGLIB-enhanced proxy, and that there's a fully initialized bean in the target field of the proxy. I'll attach a screenshot of some debugging data.
In summary; the entity was retrieved via a lazy fetch, appears the be correct, seems to be in the session and yet the exception occurs.
I've tried to resolve this by re-fetching the object from the session, and a few other tries, with no luck.
--
This message is automatically generated by JIRA.
-
If you think it was sent incorrectly contact one of the administrators: http://opensource.atlassian.com/projects/hibernate/secure/Administrators....
-
For more information on JIRA, see: http://www.atlassian.com/software/jira
15 years, 3 months
[Hibernate-JIRA] Created: (HHH-3332) Hibernate duplicate then child entity's on merge
by Rodrigo de Assumpção (JIRA)
Hibernate duplicate then child entity's on merge
------------------------------------------------
Key: HHH-3332
URL: http://opensource.atlassian.com/projects/hibernate/browse/HHH-3332
Project: Hibernate3
Issue Type: Bug
Affects Versions: 3.2.6
Environment: JDK 1.6
Oracle 9i
Hibernate 3.2.6
Hibernate Annotations 3.3.1
Hibernate EntityManager 3.3.2
Standalone Running
Reporter: Rodrigo de Assumpção
Priority: Critical
The method merge from EntityManager causes a duplication of child entity's.
class Father:
@OneToMany(mappedBy = "father", cascade={CascadeType.ALL}, fetch=FetchType.LAZY)
private List<Child> childList;
class Child:
@ManyToOne @JoinColumn(name = "ID_FATHER")
private Father father;
class BugTest
EntityManagerFactory emf = Persistence.createEntityManagerFactory("JpaTestHB");
EntityManager em = emf.createEntityManager();
Father f = (Father) em.createQuery("SELECT f FROM Father f WHERE f.id = 1").getSingleResult();
Child c = new Child();
c.setFather(f);
f.getChildList().add(c);
em.getTransaction().begin();
em.merge(f);
em.getTransaction().commit();
The execution of BugTest Class causes tow insert's on table "child".
If you change the fetch mode to EAGER (into Father class) the problem not occurs.
I make the same test with Toplink, and it make a unique insert, normal.
--
This message is automatically generated by JIRA.
-
If you think it was sent incorrectly contact one of the administrators: http://opensource.atlassian.com/projects/hibernate/secure/Administrators....
-
For more information on JIRA, see: http://www.atlassian.com/software/jira
15 years, 3 months
[Hibernate-JIRA] Created: (HHH-5280) "java.lang.IllegalArgumentException: object is not an instance of declaring class" when persisting a object graph containing the same transient objetc twice.
by Benjamin Lerman (JIRA)
"java.lang.IllegalArgumentException: object is not an instance of declaring class" when persisting a object graph containing the same transient objetc twice.
-------------------------------------------------------------------------------------------------------------------------------------------------------------
Key: HHH-5280
URL: http://opensource.atlassian.com/projects/hibernate/browse/HHH-5280
Project: Hibernate Core
Issue Type: Bug
Components: core
Affects Versions: 3.5.2
Environment: Hibernate 3.5.2
Db: All? (At least h2 and mysql)
Reporter: Benjamin Lerman
Priority: Critical
Attachments: hibernate-multi-parent.tgz, test.entity.TestCreate.txt
I attach a maven project showing the bug.
I have 3 classes, A, B, C with
C have a one-to-many unidirectional relation to B and A.
B have a one-to-many unidirectional relation to A.
Those relations are mapped by foreign keys.
The cascading properties for those relations are all save-update,persist
For each of those relations, the inverse cardinality is 1 (which means A must be associated with a B and a C, and B must be associated with a C).
I create an instance of C that I associate to an instance of B and an instance of A, and I associate the instance of B with the instance of A.
I then try to save C, and I get the attached exception.
For what I understood the problem is with the method StatefulPersistenceContext.getOwnerId: this method use a cache to retrieve the parent of the instance of A, but because A has 2 different parents (the instance of B and the instance of C), it does not retrieve the right one and try to call a method on the wrong entity.
--
This message is automatically generated by JIRA.
-
If you think it was sent incorrectly contact one of the administrators: http://opensource.atlassian.com/projects/hibernate/secure/Administrators....
-
For more information on JIRA, see: http://www.atlassian.com/software/jira
15 years, 3 months
[Hibernate-JIRA] Created: (HHH-3608) DB sequence numbers are not unique when using the pooled SequenceStyleGenerator in multiple JVMs with the same DB
by Matthias Gommeringer (JIRA)
DB sequence numbers are not unique when using the pooled SequenceStyleGenerator in multiple JVMs with the same DB
-----------------------------------------------------------------------------------------------------------------
Key: HHH-3608
URL: http://opensource.atlassian.com/projects/hibernate/browse/HHH-3608
Project: Hibernate Core
Issue Type: Bug
Components: core
Affects Versions: 3.3.1, 3.3.0.SP1, 3.3.0.GA, 3.2.6
Environment: Hibernate 3.2.6, Oracle (any version)
Reporter: Matthias Gommeringer
Priority: Blocker
Attachments: PooledOptimizerTest.java
We have several Application Servers (=JVMs) running each of them using Hibernate-Objects with the SequenceStyleGenerator+pooled configured. In unpredictable time intervals it happens that hibernate assigns the same ID to two completely different objects which results in a UniqueConstraintViolation exception from the database. Here an example with a description where hibernate fails:
DB-Sequence setup:
start=0
increment=2
PooledOptimizer.generate() with 2 threads (first assignment of hiValue/value):
JVM-1 JVM-2
value=0=callback.nextval
value=2=callback.nextval
hiValue=4=callback.nextval
hiValue=6=callback.nextval
The problem's cause is in the PooledOptimizer.generate: when it initializes
the value+hiValue for the first time it invokes callback.nextValue() twice which
may provide values that do not belong to each other. The reason is that
between the assignment of "value" and "hiValue" another JVM can retrieve a
DB sequence value from the callback which leads to an inconsistent "value" and "hiValue"
relation (see example above).
A fix that works for multiple JVMs would be to invoke the "callback.getNextValue()" maximum once
per "optimizer.generate()" call:
public synchronized Serializable generate(AccessCallback callback) {
if ( hiValue < 0 ) {
value = callback.getNextValue();
hiValue = value + incrementSize;
}
else if ( value >= hiValue ) {
value = callback.getNextValue();
hiValue = value + incrementSize;
}
return make(value++);
}
I attached a testcase that prooves the described problem (you can see that the IDs "2" and "3" are assigned two times).
I would be very thankful if this problem could be fixed very soon since it is a showstopper which
occurs very unpredictably.
--
This message is automatically generated by JIRA.
-
If you think it was sent incorrectly contact one of the administrators: http://opensource.atlassian.com/projects/hibernate/secure/Administrators....
-
For more information on JIRA, see: http://www.atlassian.com/software/jira
15 years, 3 months
[Hibernate-JIRA] Created: (HHH-3551) Boolean substitution in informix
by Rouvignac (JIRA)
Boolean substitution in informix
--------------------------------
Key: HHH-3551
URL: http://opensource.atlassian.com/projects/hibernate/browse/HHH-3551
Project: Hibernate Core
Issue Type: Bug
Components: query-sql
Affects Versions: 3.3.1
Environment: Hibernate 3.2
Informix 9.40
Reporter: Rouvignac
HQL Query :
select order from Order order where order.printed = ?
Parameter :
true, false, Boolean.TRUE or Boolean.FALSE
When the request is executed we get the following error :
SQLSTATE: IX000
SQL CODE: -674
674: Routine (equal) can not be resolved.
If as parameter we use "t" ot "f" everything works fine but it will not work with other DB.
As a workaround we can use :
property name="hibernate.query.substitutions">true t, false f</property>
I investigated in Dialects :
Dialect.java
public String toBooleanValueString(boolean bool) {
return bool ? "1" : "0";
}
PostgreSQLDialect.java
public String toBooleanValueString(boolean bool) {
return bool ? "true" : "false";
}
InformixDialect.java uses Dialect.java toBooleanValueString method.
In my mind toBooleanValueString should be added to InformixDialect.java as follow :
public String toBooleanValueString(boolean bool) {
return bool ? "t" : "f";
}
--
This message is automatically generated by JIRA.
-
If you think it was sent incorrectly contact one of the administrators: http://opensource.atlassian.com/projects/hibernate/secure/Administrators....
-
For more information on JIRA, see: http://www.atlassian.com/software/jira
15 years, 3 months
[Hibernate-JIRA] Created: (HHH-4511) Problems with polymorphic queries with SINGLE_TABLE inheritance strategy
by Karoly Gacsal (JIRA)
Problems with polymorphic queries with SINGLE_TABLE inheritance strategy
------------------------------------------------------------------------
Key: HHH-4511
URL: http://opensource.atlassian.com/projects/hibernate/browse/HHH-4511
Project: Hibernate Core
Issue Type: Bug
Components: envers
Affects Versions: 3.5.0.Beta-1
Environment: envers 1.2.1
Hibernate 3.3.2
Reporter: Karoly Gacsal
Attachments: ChildAuditing.java
Inheritance strategy is SINGLE_TABLE (discriminator).
When I query for ParentType I do not get ChildType instances in the result, but ParentType instances.
I checked the problem against envers 1.2.1/Hibernate 3.3.2 and against Hibernate 3.5.0.Beta-1 too.
The testcase "\src\test\java\org\hibernate\envers\test\integration\inheritance\single\ChildAuditing.java"
passes, but when I change the two sides of the equals method in testPolymorphicQuery()'s second assert the testcase fails, because
the expected result is a ChildEntity, but in the result we get an instance of ParentEntity.
Attached you can find the testcases changed by me.
--
This message is automatically generated by JIRA.
-
If you think it was sent incorrectly contact one of the administrators: http://opensource.atlassian.com/projects/hibernate/secure/Administrators....
-
For more information on JIRA, see: http://www.atlassian.com/software/jira
15 years, 3 months
[Hibernate-JIRA] Created: (HHH-3524) setFetchMode ignored if using createCriteria
by Peter Weemeeuw (JIRA)
setFetchMode ignored if using createCriteria
--------------------------------------------
Key: HHH-3524
URL: http://opensource.atlassian.com/projects/hibernate/browse/HHH-3524
Project: Hibernate Core
Issue Type: Bug
Components: query-criteria
Affects Versions: 3.2.5
Environment: Hibernate 3.2.5, Oracle 8
Reporter: Peter Weemeeuw
Hi,
It seems that criteria.setFetchMode gets ignored if you combine it with createCriteria to add a restriction.
This works as expected:
DetachedCriteria c = DetachedCriteria.forClass(MenuItem.class);
c.setFetchMode("menuItemSubscriptions", FetchMode.JOIN);
But in this case the join doesn't happen (and I get a LazyInstantiationException further on).
DetachedCriteria c = DetachedCriteria.forClass(MenuItem.class);
c.setFetchMode("menuItemSubscriptions", FetchMode.JOIN);
c.createCriteria("menuItemSubscriptions").add(
Restrictions.eq("location", "B")
);
This does not happen if I set lazy="false" in the mappings
file.
Regards,
Peter
--
This message is automatically generated by JIRA.
-
If you think it was sent incorrectly contact one of the administrators: http://opensource.atlassian.com/projects/hibernate/secure/Administrators....
-
For more information on JIRA, see: http://www.atlassian.com/software/jira
15 years, 3 months
[Hibernate-JIRA] Created: (ANN-747) @CollectionOfElements does not cascade on delete
by Nicole Rauch (JIRA)
@CollectionOfElements does not cascade on delete
------------------------------------------------
Key: ANN-747
URL: http://opensource.atlassian.com/projects/hibernate/browse/ANN-747
Project: Hibernate Annotations
Issue Type: Bug
Affects Versions: 3.3.1.GA
Environment: Hibernate 3.2.6 GA
Database: H2 1.0.72
Reporter: Nicole Rauch
Consider the following constellation:
@Embeddable
public class Foo {
// ...
}
@Entity
public class Bar {
@CollectionOfElements
private Set<Foo> myFoos;
// ...
}
When I persist a Bar object that contains some Foos, and when I later decide to delete the Bar object, I get a foreign key constraint violation error message because the Foo objects, which contain a reference to the Bar object that owns them, are not deleted automatically. I would expect the default behaviour to be "on delete cascade" because the Foo objects are embeddables, thus they cannot exist on their own without the Bar object that owns them. But there is no way to tell Hibernate to cascade:
- the @OnDelete annotation is only allowed for OneToMany relations
- the @Cascade annotation is being ignored
- there is no "cascade" property for the CollectionOfElements
So my question is: Why does the cascading not occur automatically, and how do I tell Hibernate to cascade anyways?
Thanks a lot in advance,
Nicole
--
This message is automatically generated by JIRA.
-
If you think it was sent incorrectly contact one of the administrators: http://opensource.atlassian.com/projects/hibernate/secure/Administrators....
-
For more information on JIRA, see: http://www.atlassian.com/software/jira
15 years, 4 months
[Hibernate-JIRA] Created: (HHH-3273) One-to-Many relationship not working with custom Loader
by Darren Hicks (JIRA)
One-to-Many relationship not working with custom Loader
--------------------------------------------------------
Key: HHH-3273
URL: http://opensource.atlassian.com/projects/hibernate/browse/HHH-3273
Project: Hibernate3
Issue Type: Bug
Affects Versions: 3.2.6, 3.2.5, 3.2.4, 3.2.3, 3.2.2, 3.2.1
Environment: hibernate-3.2.6.jar
Reporter: Darren Hicks
Within the context of a One-to-Many relationship, NamedQueryCollectionInitializer .initialize() never actually populates the PersistantBag on the parent after it calls query.setCollectionKey( key ).setFlushMode( FlushMode.MANUAL ).list() to retrieve the children.
This is documented in the forums here: http://forums.hibernate.org/viewtopic.php?t=986428
Additionally, the poster has a fix posted which may solve the problem, or at least lay out the groundwork for a solution. Here is the proposed implementation of NamedQueryCollectionInitializer.initialize():
public void initialize(Serializable key, SessionImplementor session)
throws HibernateException {
if (log.isDebugEnabled()) {
log.debug("initializing collection: " + persister.getRole()
+ " using named query: " + queryName);
}
// TODO: is there a more elegant way than downcasting?
AbstractQueryImpl query = (AbstractQueryImpl) session
.getNamedSQLQuery(queryName);
if (query.getNamedParameters().length > 0) {
query.setParameter(query.getNamedParameters()[0], key, persister
.getKeyType());
} else {
query.setParameter(0, key, persister.getKeyType());
}
List list = query.setCollectionKey(key).setFlushMode(FlushMode.MANUAL)
.list();
// Uh, how 'bout we save the collection for later retrieval?
CollectionKey collectionKey = new CollectionKey(persister, key, session
.getEntityMode());
for (Object object : session.getPersistenceContext()
.getCollectionsByKey().keySet()) {
if (collectionKey.equals(object)) {
PersistentCollection persistentCollection = session
.getPersistenceContext().getCollection(collectionKey);
Serializable[] serializables = new Serializable[list.size()];
for (int i = 0; i < list.size(); i++) {
serializables[i] = persister.getElementType().disassemble(
list.get(i), session,
persistentCollection.getOwner());
}
persistentCollection.initializeFromCache(persister,
serializables, persistentCollection.getOwner());
persistentCollection.setSnapshot(key, persistentCollection
.getRole(), serializables);
persistentCollection.afterInitialize();
session.getPersistenceContext().getCollectionEntry(
persistentCollection).postInitialize(
persistentCollection);
}
}
}
--
This message is automatically generated by JIRA.
-
If you think it was sent incorrectly contact one of the administrators: http://opensource.atlassian.com/projects/hibernate/secure/Administrators....
-
For more information on JIRA, see: http://www.atlassian.com/software/jira
15 years, 4 months
[Hibernate-JIRA] Created: (EJB-328) Missing flush before lock() when LockModeType is AUTO
by Per Olesen (JIRA)
Missing flush before lock() when LockModeType is AUTO
-----------------------------------------------------
Key: EJB-328
URL: http://opensource.atlassian.com/projects/hibernate/browse/EJB-328
Project: Hibernate Entity Manager
Issue Type: Bug
Components: EntityManager
Affects Versions: 3.3.1.GA
Environment: core: 3.2.5.ga
entitymanager: 3.3.1.ga
annotations: 3.3.0.ga
Reporter: Per Olesen
Priority: Minor
When I try to WRITE lock() a newly persisted entity using entityManager.lock, I get a StaleObjectStateException, telling me that some other transaction updated or deleted the row. I am doing this in the same transaction (persist and lock).
By digging into the code, I see that the exception is thrown inside the SelectLockingStrategy.lock method, around these lines:
ResultSet rs = st.executeQuery();
try {
if ( !rs.next() ) {
if ( factory.getStatistics().isStatisticsEnabled() ) {
factory.getStatisticsImplementor()
.optimisticFailure( lockable.getEntityName() );
}
throw new StaleObjectStateException( lockable.getEntityName(), id );
}
}
The query executed here is the one which performs the select on id with FOR UPDATE. This select finds nothing, hence the exception.
Setting show_sql = true shows me, that no insert is performed. Debugging the flush mode tells me, that it is set to AUTO.
Shouldn't AUTO flush mode have the side effect, that a flush is performed before a query?
Performing an explicit flush, before the lock, makes everything green :-), so this is my current work-around.
Here is the exception (sanitized for company info):
org.springframework.orm.jpa.JpaOptimisticLockingFailureException: nested exception is javax.persistence.OptimisticLockException
Caused by: javax.persistence.OptimisticLockException
at org.hibernate.ejb.AbstractEntityManagerImpl.wrapStaleStateException(AbstractEntityManagerImpl.java:643)
at org.hibernate.ejb.AbstractEntityManagerImpl.throwPersistenceException(AbstractEntityManagerImpl.java:600)
at org.hibernate.ejb.AbstractEntityManagerImpl.lock(AbstractEntityManagerImpl.java:379)
...
Caused by: org.hibernate.StaleObjectStateException: Row was updated or deleted by another transaction (or unsaved-value mapping was incorrect): [com.foo.bar#32]
at org.hibernate.dialect.lock.SelectLockingStrategy.lock(SelectLockingStrategy.java:78)
at org.hibernate.persister.entity.AbstractEntityPersister.lock(AbstractEntityPersister.java:1334)
at org.hibernate.event.def.AbstractLockUpgradeEventListener.upgradeLock(AbstractLockUpgradeEventListener.java:88)
at org.hibernate.event.def.DefaultLockEventListener.onLock(DefaultLockEventListener.java:64)
at org.hibernate.impl.SessionImpl.fireLock(SessionImpl.java:584)
at org.hibernate.impl.SessionImpl.lock(SessionImpl.java:576)
at org.hibernate.ejb.AbstractEntityManagerImpl.lock(AbstractEntityManagerImpl.java:376)
...
--
This message is automatically generated by JIRA.
-
If you think it was sent incorrectly contact one of the administrators: http://opensource.atlassian.com/projects/hibernate/secure/Administrators....
-
For more information on JIRA, see: http://www.atlassian.com/software/jira
15 years, 4 months
[Hibernate-JIRA] Created: (ANN-848) Bidirectional Polymorphism
by Yong Joo Jeong (JIRA)
Bidirectional Polymorphism
--------------------------
Key: ANN-848
URL: http://opensource.atlassian.com/projects/hibernate/browse/ANN-848
Project: Hibernate Annotations
Issue Type: New Feature
Components: binder
Affects Versions: 3.4.0.GA
Environment: 3.4.0.GA, Any database
Reporter: Yong Joo Jeong
I'm trying to implement bidirectional polymorphic class.
Code:
public class Order{
...
@Any( metaColumn = @Column( name = "item_type" ), fetch=FetchType.EAGER )
@AnyMetaDef(
idType = "long",
metaType = "string",
metaValues = {
@MetaValue( value = "ItemA", targetEntity = ItemA.class ),
@MetaValue( value = "ItemB", targetEntity = ItemB.class )
} )
@JoinColumn( name = "item_id" )
Object item;
...
}
And trying to do somthing like the following
Code:
public class ItemA {
@OneToAny // like @OneToMany; in Order table there are "item_id" and "item_type" fields to distinguish ItemA and ItemB
List<Order> orders;
...
}
RoR support this kind of relationship, but I can't find it from Hibernate.
Inheritance with "Table per class" is not an option since it does not support the IDENTITY generator strategy.
Any solution for this?
--
This message is automatically generated by JIRA.
-
If you think it was sent incorrectly contact one of the administrators: http://opensource.atlassian.com/projects/hibernate/secure/Administrators....
-
For more information on JIRA, see: http://www.atlassian.com/software/jira
15 years, 4 months
[Hibernate-JIRA] Created: (HBX-1092) hbm2doc with graphing fails on MacOSX
by Avram Cherry (JIRA)
hbm2doc with graphing fails on MacOSX
-------------------------------------
Key: HBX-1092
URL: http://opensource.atlassian.com/projects/hibernate/browse/HBX-1092
Project: Hibernate Tools
Issue Type: Bug
Components: hbm2doc
Affects Versions: 3.2.0.GA, 3.2.2
Reporter: Avram Cherry
In the method org.hibernate.tool.hbm2x.DocExporter.dotToFile, the portions of the command passed to Runtime.exec() are being passed to an escape(String) method that optionally adds quotes to the executable file path and the path to the input file, but only if the OS is not linux. MacOSX is not linux, but adding quotes causes exec() to fail.
The solution is to change the following statement:
String exeCmd = escape(dotExeFileName) + " -T" + getFormatForFile(outFileName) + " " + escape(dotFileName) + " -o " + escape(outFileName);
to:
String[] exeCmd = new String[] {dotExeFileName, " -T", getFormatForFile(outFileName), dotFileName, " -o ", outFileName};
If you pass the command and arguments as separate strings within an array to Runtime.exec() you do not need to quote filenames, regardless of platform.
A (potentially very harmful) workaround is to pass -Dos.name=Linux to the VM.
Please note that I've checked both the 3.2 branch and trunk and both contain the same problem.
--
This message is automatically generated by JIRA.
-
If you think it was sent incorrectly contact one of the administrators: http://opensource.atlassian.com/projects/hibernate/secure/Administrators....
-
For more information on JIRA, see: http://www.atlassian.com/software/jira
15 years, 4 months
[Hibernate-JIRA] Created: (HHH-5265) @Formula adds a this_. prefix to an SQL function
by Matthias Bosshard (JIRA)
@Formula adds a this_. prefix to an SQL function
------------------------------------------------
Key: HHH-5265
URL: http://opensource.atlassian.com/projects/hibernate/browse/HHH-5265
Project: Hibernate Core
Issue Type: Bug
Components: annotations, core
Affects Versions: 3.5.2
Environment: Hibernate 3.5.2, with a SQL Anywhere 10 and the org.hibernate.dialect.SybaseDialect
Reporter: Matthias Bosshard
With Hibernate 3.5.2 the ISNULL/COALESCE SQL statement in the following @Formula is prefixed with a this_. An so its no valid SQL.
The annotation:
@Formula( "(SELECT ISNULL ( (SELECT 1 WHERE EXISTS (SELECT * FROM org.usertable as user WHERE user.user_id = user_id)), 0))" )
The SQL part for this formula:
(SELECT *this_.ISNULL* ( (SELECT 1 WHERE EXISTS (SELECT * FROM org.usertable as user WHERE user.user_id = this_.user_id)), 0)) as formula8_1_,
-> thats invalid SQL
In Hibernate 3.5.1 the SQL is pretty the same, but without this_. before ISNULL.
(SELECT *ISNULL* ( (SELECT 1 WHERE EXISTS (SELECT * FROM org.usertable as user WHERE user.user_id = this_.user_id)), 0)) as formula8_1_,
--
This message is automatically generated by JIRA.
-
If you think it was sent incorrectly contact one of the administrators: http://opensource.atlassian.com/projects/hibernate/secure/Administrators....
-
For more information on JIRA, see: http://www.atlassian.com/software/jira
15 years, 4 months
[Hibernate-JIRA] Created: (HHH-3824) OneToOne join by Non-primary key column throws PropertyAccessException when join column is String
by sathish (JIRA)
OneToOne join by Non-primary key column throws PropertyAccessException when join column is String
-------------------------------------------------------------------------------------------------
Key: HHH-3824
URL: http://opensource.atlassian.com/projects/hibernate/browse/HHH-3824
Project: Hibernate Core
Issue Type: Bug
Components: query-criteria, query-hql
Affects Versions: 3.3.1
Environment: Microsoft SQL server 2005, Hibernate 3.3.1
Reporter: sathish
Attachments: trace.txt
When i try to join 2 entities by OneToOne using a Non-primary key column, it throws the following exception:
org.hibernate.PropertyAccessException: could not get a field value by reflection getter of com.xxx.domain.Inventory.sku
Caused by: java.lang.IllegalArgumentException: Can not set java.lang.String field com.inwk.estore.server.domain.Inventory.sku to java.lang.Integer
[Full stacktrace attached]
sku is the Non-primary key String join column by which im trying to do a OneToOne join between Item and Inventory entity.
Apparently its trying to interpret Sku as an Integer column. Adding columnDefinition as VARCHAR/String doesn't help either
Mappings for Item and Inventory are below:
class Item{
@Id
Long id;
@Column
String sku;
//some more properties
@OneToOne(optional = true)
@JoinColumn(name = "sku", referencedColumnName = "sku", insertable = false, updatable = false)
Inventory inventory;
}
class Inventory{
@Id
Long id
@Column
String sku
@Column
Long quantity;
}
--
This message is automatically generated by JIRA.
-
If you think it was sent incorrectly contact one of the administrators: http://opensource.atlassian.com/projects/hibernate/secure/Administrators....
-
For more information on JIRA, see: http://www.atlassian.com/software/jira
15 years, 4 months