December 2010 - hibernate-issues - Jboss List Archives

[Hibernate-JIRA] Created: (HSEARCH-361) Only index an entity if an indexed property has changed

by Emmanuel Bernard (JIRA)

Only index an entity if an indexed property has changed ------------------------------------------------------- Key: HSEARCH-361 URL: http://opensource.atlassian.com/projects/hibernate/browse/HSEARCH-361 Project: Hibernate Search Issue Type: New Feature Reporter: Emmanuel Bernard Fix For: 3.2.0 PostUpdateEvent has state and oldState and EntityPersister has getPropertyNames() and findDirty() -- 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

7
32
0 / 0

[Hibernate-JIRA] Created: (HSEARCH-652) Cache NumericField usage in Delete operation for single entity-per-index case

by Sanne Grinovero (JIRA)

Cache NumericField usage in Delete operation for single entity-per-index case ----------------------------------------------------------------------------- Key: HSEARCH-652 URL: http://opensource.atlassian.com/projects/hibernate/browse/HSEARCH-652 Project: Hibernate Search Issue Type: Improvement Components: engine Reporter: Sanne Grinovero Assignee: Sanne Grinovero Priority: Minor Fix For: 3.4.0 org.hibernate.search.backend.impl.lucene.works.DeleteExtWorkDelegate has some extra knowledge on the model which is not being used -- 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

2
2
0 / 0

[Hibernate-JIRA] Created: (HSEARCH-651) Improve error reporting on null values in querybuilder DSL

by Sanne Grinovero (JIRA)

Improve error reporting on null values in querybuilder DSL ---------------------------------------------------------- Key: HSEARCH-651 URL: http://opensource.atlassian.com/projects/hibernate/browse/HSEARCH-651 Project: Hibernate Search Issue Type: Improvement Components: query Reporter: Sanne Grinovero Assignee: Sanne Grinovero Priority: Trivial Fix For: 3.4.0 >From forum thread: https://forum.hibernate.org/viewtopic.php?f=9&t=1008832 Something wrong, but there's a typo in first error message and the NPE definitely doesn't help understand the issue. -- 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

2
2
0 / 0

[Hibernate-JIRA] Created: (HSEARCH-650) Regression in 3.3.0: Using hibernate.use_identifier_rollback property causes exceptions on deletes

by Kyrill Alyoshin (JIRA)

Regression in 3.3.0: Using hibernate.use_identifier_rollback property causes exceptions on deletes -------------------------------------------------------------------------------------------------- Key: HSEARCH-650 URL: http://opensource.atlassian.com/projects/hibernate/browse/HSEARCH-650 Project: Hibernate Search Issue Type: Bug Components: engine Affects Versions: 3.3.0.Final Environment: Hibernate 3.6.0, Hibernate Search 3.3.0 Reporter: Kyrill Alyoshin Basically, when Hibernate is configured with 'hibernate.use_identifier_rollback' (that is to set primary keys of the deleted entities to null), here is what happens: {code} 2010-12-17 18:52:51,187 TRACE [Hibernate Search: Directory writer-1|] org.hibernate.search.backend.impl.lucene.works.DeleteExtWorkDelegate => Removing class xxx.Vendor#null by id using an IndexWriter. 2010-12-17 18:52:51,187 ERROR [Hibernate Search: Directory writer-1|] org.hibernate.search.backend.impl.lucene.PerDPQueueProcessor => Unexpected error in Lucene Backend: java.lang.NullPointerException at org.apache.lucene.index.TermBuffer.set(TermBuffer.java:95) at org.apache.lucene.index.SegmentTermEnum.scanTo(SegmentTermEnum.java:160) at org.apache.lucene.index.TermInfosReader.get(TermInfosReader.java:232) at org.apache.lucene.index.TermInfosReader.get(TermInfosReader.java:179) at org.apache.lucene.index.SegmentTermDocs.seek(SegmentTermDocs.java:57) at org.apache.lucene.index.DocumentsWriter.applyDeletes(DocumentsWriter.java:1046) at org.apache.lucene.index.DocumentsWriter.applyDeletes(DocumentsWriter.java:1004) at org.apache.lucene.index.IndexWriter.applyDeletes(IndexWriter.java:4566) at org.apache.lucene.index.IndexWriter.doFlushInternal(IndexWriter.java:3756) at org.apache.lucene.index.IndexWriter.doFlush(IndexWriter.java:3595) at org.apache.lucene.index.IndexWriter.flush(IndexWriter.java:3585) at org.apache.lucene.index.IndexWriter.closeInternal(IndexWriter.java:1717) at org.apache.lucene.index.IndexWriter.close(IndexWriter.java:1680) at org.apache.lucene.index.IndexWriter.close(IndexWriter.java:1644) at org.hibernate.search.backend.Workspace.closeIndexWriter(Workspace.java:211) at org.hibernate.search.backend.impl.lucene.PerDPQueueProcessor.run(PerDPQueueProcessor.java:113) at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441) at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303) at java.util.concurrent.FutureTask.run(FutureTask.java:138) at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908) at java.lang.Thread.run(Thread.java:662) 2010-12-17 18:52:51,187 ERROR [Hibernate Search: Directory writer-1|] org.hibernate.search.exception.impl.LogErrorHandler => Exception occurred java.lang.NullPointerException Primary Failure: Entity xxx.Vendor Id null Work Type org.hibernate.search.backend.DeleteLuceneWork java.lang.NullPointerException at org.apache.lucene.index.TermBuffer.set(TermBuffer.java:95) at org.apache.lucene.index.SegmentTermEnum.scanTo(SegmentTermEnum.java:160) at org.apache.lucene.index.TermInfosReader.get(TermInfosReader.java:232) at org.apache.lucene.index.TermInfosReader.get(TermInfosReader.java:179) at org.apache.lucene.index.SegmentTermDocs.seek(SegmentTermDocs.java:57) at org.apache.lucene.index.DocumentsWriter.applyDeletes(DocumentsWriter.java:1046) at org.apache.lucene.index.DocumentsWriter.applyDeletes(DocumentsWriter.java:1004) at org.apache.lucene.index.IndexWriter.applyDeletes(IndexWriter.java:4566) at org.apache.lucene.index.IndexWriter.doFlushInternal(IndexWriter.java:3756) at org.apache.lucene.index.IndexWriter.doFlush(IndexWriter.java:3595) at org.apache.lucene.index.IndexWriter.flush(IndexWriter.java:3585) at org.apache.lucene.index.IndexWriter.closeInternal(IndexWriter.java:1717) at org.apache.lucene.index.IndexWriter.close(IndexWriter.java:1680) at org.apache.lucene.index.IndexWriter.close(IndexWriter.java:1644) at org.hibernate.search.backend.Workspace.closeIndexWriter(Workspace.java:211) at org.hibernate.search.backend.impl.lucene.PerDPQueueProcessor.run(PerDPQueueProcessor.java:113) at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441) at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303) at java.util.concurrent.FutureTask.run(FutureTask.java:138) at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908) at java.lang.Thread.run(Thread.java:662) 2010-12-17 18:52:51,187 WARN [Hibernate Search: Directory writer-1|] org.hibernate.search.backend.Workspace => going to force release of the IndexWriter lock {code} This has not happened in 3.2.1 and Hibernate 3.5.4. I believe this is a serious regression issue. -- 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

3
4
0 / 0

[Hibernate-JIRA] Created: (EJB-397) native SQL queries in hibernate don't work when using aliases to differentiate columns that have the same name

by Alex McCarrier (JIRA)

native SQL queries in hibernate don't work when using aliases to differentiate columns that have the same name -------------------------------------------------------------------------------------------------------------- Key: EJB-397 URL: http://opensource.atlassian.com/projects/hibernate/browse/EJB-397 Project: Hibernate Entity Manager Issue Type: Bug Components: EntityManager Affects Versions: 3.3.2.GA Environment: jboss 4.2.2, mysql 5 Reporter: Alex McCarrier Basically same as HHH-2094, if you do something like this: select oldForm.data as oldData newForm.data as newData from form oldForm, join form newForm on oldForm.replaced_by_id = newForm.id then use entityManager.createNativeQuery(sql).getResultList() it will end up with an error that says column named oldData does not exist. If you take out the aliases, then it will just return the first value for "data" for every column. If you run this through straight JDBC with the alias, it works as expected. -- 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

3
2
0 / 0

[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

2
2
0 / 0

[Hibernate-JIRA] Created: (BVAL-85) Support dynamic default group sequence definition

by Emmanuel Bernard (JIRA)

Support dynamic default group sequence definition ------------------------------------------------- Key: BVAL-85 URL: http://opensource.atlassian.com/projects/hibernate/browse/BVAL-85 Project: Bean Validation Issue Type: New Feature Components: ri-general Reporter: Emmanuel Bernard Will probably not be spec'ed in the 1.0 JSR but can be added as a RI feature. -- 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

4
22
0 / 0

[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

5
5
0 / 0

[Hibernate-JIRA] Created: (METAGEN-46) Add ability to specify a desired package

by Srgjan Srepfler (JIRA)

Add ability to specify a desired package ---------------------------------------- Key: METAGEN-46 URL: http://opensource.atlassian.com/projects/hibernate/browse/METAGEN-46 Project: Hibernate Metamodel Generator Issue Type: Improvement Reporter: Srgjan Srepfler Assignee: Hardy Ferentschik Priority: Minor It would be nice if one could specify an optional path/package for the generated sources. That way, one can have the metamodel in a separate package. Usefull if one likes to version generated sources. -- 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

3
9
0 / 0

[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

3
4
0 / 0

2026

2025

2024

2023

2022

2021

2020

2019

2018

2017

2016

2015

2014

2013

2012

2011

2010

2009

2008

2007

2006

hibernate-issues December 2010