[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
13 years, 7 months
- 4
- 22
[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
13 years, 7 months
- 5
- 5
[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
13 years, 7 months
- 3
- 4
[Hibernate-JIRA] Created: (HHH-3123) NullPointerException on invalid HQL query with an extra brace
by Geoffrey De Smet (JIRA)
NullPointerException on invalid HQL query with an extra brace
-------------------------------------------------------------
Key: HHH-3123
URL: http://opensource.atlassian.com/projects/hibernate/browse/HHH-3123
Project: Hibernate3
Issue Type: Bug
Components: query-hql
Affects Versions: 3.2.5
Reporter: Geoffrey De Smet
Priority: Trivial
This query:
"select p from IndividueleRekeningKasPO p left join fetch p.irTotalen inner join fetch p.toegangIndividueleRekeningKas tirkas where tirkas.authorityRef in (:authorityref)) and p.soort = :soort and p.id > 0"
gives a NPE. The strange thing is that this query executes:
"select p from IndividueleRekeningKasPO p left join fetch p.irTotalen inner join fetch p.toegangIndividueleRekeningKas tirkas where tirkas.authorityRef in (:authorityref)) and p.id > 0"
both are invalid, because there is a closing brace to much in "(:authorityref))".
--
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
13 years, 7 months
- 2
- 2
[Hibernate-JIRA] Created: (HHH-5019) @TableGenerator throws Unsupported exception - error performing isolated work
by Rohini (JIRA)
@TableGenerator throws Unsupported exception - error performing isolated work
-----------------------------------------------------------------------------
Key: HHH-5019
URL: http://opensource.atlassian.com/projects/hibernate/browse/HHH-5019
Project: Hibernate Core
Issue Type: Bug
Affects Versions: 3.3.1, 3.3.0.SP1, 3.3.0.GA, 3.3.0.CR2, 3.3.0.CR1, 3.2.7, 3.2.6, 3.2.5, 3.2.4.sp1, 3.2.4, 3.2.3, 3.2.2, 3.2.1
Environment: Hibernate Core 3.3.1, MySQL, Websphere 6.1 with EJB3.0 Feature pack
Reporter: Rohini
While implementing GenerationType.TABLE strategy with Hibernate as the persistence provider, id generation throws
javax.persistence.PersistenceException: org.hibernate.HibernateException: error performing isolated work
[3/18/10 14:40:41:533 IST] 0000002d SystemErr R at org.hibernate.ejb.AbstractEntityManagerImpl.throwPersistenceException(AbstractEntityManagerImpl.java:614)
--------------------------------------------------------------
3/18/10 14:40:41:533 IST] 0000002d SystemErr R Caused by: org.hibernate.HibernateException: error performing isolated work
at org.hibernate.engine.transaction.Isolater$JtaDelegate.delegateWork(Isolater.java:166)
at org.hibernate.engine.transaction.Isolater.doIsolatedWork(Isolater.java:64)
at org.hibernate.engine.TransactionHelper.doWorkInNewTransaction(TransactionHelper.java:74)
at org.hibernate.id.MultipleHiLoPerTableGenerator.generate(MultipleHiLoPerTableGenerator.java:210)
Looking at the
Isolater.doIsolatedWork( work, session );, implementation
try {
// First we need to suspend any current JTA transaction and obtain
// a JDBC connection
surroundingTransaction = transactionManager.suspend();
if ( log.isDebugEnabled() ) {
log.debug( "surrounding JTA transaction suspended [" + surroundingTransaction + "]" );
}
This happnes only with WebsphereExtendedTransactionManagerLookup as the hibernate.transaction.manager_lookup_class.
--
This message is automatically generated by JIRA.
-
If you think it was sent incorrectly contact one of the administrators: http://opensource.atlassian.com/projects/hibernate/secure/Administrators....
-
For more information on JIRA, see: http://www.atlassian.com/software/jira
13 years, 7 months
- 6
- 6
[Hibernate-JIRA] Created: (HHH-3934) Problem with PDF doc
by Adam Warski (JIRA)
Problem with PDF doc
--------------------
Key: HHH-3934
URL: http://opensource.atlassian.com/projects/hibernate/browse/HHH-3934
Project: Hibernate Core
Issue Type: Improvement
Components: envers
Reporter: Adam Warski
Priority: Minor
there is a problem on p.8 of the PDF documentation, the table is all
jumbled + overlapping itself.
--
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
13 years, 7 months
- 2
- 1
[Hibernate-JIRA] Created: (HHH-5057) ScrollableResults does not fetch many-to-many collections
by Jérôme Van Der Linden (JIRA)
ScrollableResults does not fetch many-to-many collections
---------------------------------------------------------
Key: HHH-5057
URL: http://opensource.atlassian.com/projects/hibernate/browse/HHH-5057
Project: Hibernate Core
Issue Type: Bug
Components: core
Affects Versions: 3.3.2
Reporter: Jérôme Van Der Linden
Priority: Blocker
I have a many-to-many relation between two objects :
{code:title=Project.java|borderStyle=solid}
@Entity
public class Project {
private List<Viperson> managers;
@ManyToMany(targetEntity = Viperson.class)
@JoinTable(name = "PRJMANAGER", joinColumns = @JoinColumn(name = "PROJECTID", nullable = false), inverseJoinColumns = @JoinColumn(name = "VIPID", nullable = false))
public List<Viperson> getManagers() {
return managers;
}
}
{code}
{code:title=Viperson.java|borderStyle=solid}
@Entity
public class Viperson {
private List<Project> projects;
@ManyToMany(mappedBy = "managers", targetEntity = Project.class)
public List<Project> getProjects() {
return projects;
}
}
{code}
And the following test (actually, it is a code from spring batch HibernateCursorItemReader I put in a testcase) :
{code}
@Test
public void testSelectAll() {
StatelessSession statelessSession = sessionFactory.openStatelessSession();
ScrollableResults cursor = statelessSession.createQuery("from Project").scroll();
Object[] data = null;
if (cursor.next()) {
data = cursor.get();
}
}
{code}
data contains a {{Project}} but {{managers}} field is *null*, +even if I add eager fetching+. I have also a {{OneToMany}} in the {{Project}} class. This one is well loaded (i have a {{PersistentBag}}).
Is there anything I miss ? I suspect a bug on that.
--
This message is automatically generated by JIRA.
-
If you think it was sent incorrectly contact one of the administrators: http://opensource.atlassian.com/projects/hibernate/secure/Administrators....
-
For more information on JIRA, see: http://www.atlassian.com/software/jira
13 years, 7 months
- 3
- 3
[Hibernate-JIRA] Created: (ANN-843) Version increment not triggered on @OneToOne property modification having inverse owner
by Guenther Demetz (JIRA)
Version increment not triggered on @OneToOne property modification having inverse owner
---------------------------------------------------------------------------------------
Key: ANN-843
URL: http://opensource.atlassian.com/projects/hibernate/browse/ANN-843
Project: Hibernate Annotations
Issue Type: Bug
Affects Versions: 3.4.0.GA
Environment: Hibernate 3.3.1.GA , Microsoft SQL Server
Reporter: Guenther Demetz
Priority: Minor
Attachments: Testcase.jar
In the revised "Java Persistence with Hibernate" book by Christian Bauer and Gavin King on page 464
there's written following about versioning:
"If you use Hibernate as JPA provider ... every value-typed property modification .. triggers a version increment."
Now I saw that Version increment indeed is not triggered on @OneToOne properties having an inverse owner (= mappedBy setted).
This allows several concurrent transactions to set the association from same object towards different targets without having a OptimistickLockException at commit.
This violates the ToOne policy! (Hibernate detects the inconsistency later when loading the property from database:
org.hibernate.HibernateException: More than one row with the given identifier was found)
Please see attached junit-testcase for reproducing the problem.
regards
Guenther Demetz
--
This message is automatically generated by JIRA.
-
If you think it was sent incorrectly contact one of the administrators: http://opensource.atlassian.com/projects/hibernate/secure/Administrators....
-
For more information on JIRA, see: http://www.atlassian.com/software/jira
13 years, 7 months
- 1
- 2
[Hibernate-JIRA] Created: (HHH-4617) Using blobs with hibernate causes error
by Radosław Smogura (JIRA)
Using blobs with hibernate causes error
---------------------------------------
Key: HHH-4617
URL: http://opensource.atlassian.com/projects/hibernate/browse/HHH-4617
Project: Hibernate Core
Issue Type: Bug
Components: core
Affects Versions: 3.5.0-Beta-2
Environment: Hibernate 3.5-b2, Glassfish v3 promoted build 74, PostgreSQL 8.3.7
Reporter: Radosław Smogura
Priority: Critical
I have entity with byte[] property annotated as @Lob and lazy fetch type, when table is createad the created column is of type oid, but when the column is read in application, the Hibernate reads the OID value instead of bytes under given oid. It's behavior like to read / write bytea.
If i remember well, auto-creating table with Hibernate creates oid column.
The proper behavior for dealing in PostgreSQL (and this behavior is in Hibernate 3.4) is to use oids.
--
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
13 years, 8 months
- 4
- 16
[Hibernate-JIRA] Created: (HHH-5163) ClassCastException when Hibernate tries to cache results using ResultTransformer
by Strong Liu (JIRA)
ClassCastException when Hibernate tries to cache results using ResultTransformer
--------------------------------------------------------------------------------
Key: HHH-5163
URL: http://opensource.atlassian.com/projects/hibernate/browse/HHH-5163
Project: Hibernate Core
Issue Type: Bug
Components: core
Affects Versions: 3.5.1
Reporter: Strong Liu
Assignee: Gail Badner
Fix For: 3.5.x, 3.6
When Hibernate executes a cacheable query using a ResultTransformer, it will attempt to cache the results AFTER applying the ResultTransformer. The problem is that the ResultTransformer may modify the data in a way that Hibernate won't understand it anymore, and in this case it will generate a ClassCastException when trying to cache it.
---------------------------
this can be reproduced by CriteriaQueryTest with following change:
papa-pc:testsuite stliu$ svn diff src/test/java/org/hibernate/test/criteria/CriteriaQueryTest.java
Index: src/test/java/org/hibernate/test/criteria/CriteriaQueryTest.java
===================================================================
--- src/test/java/org/hibernate/test/criteria/CriteriaQueryTest.java (revision 19246)
+++ src/test/java/org/hibernate/test/criteria/CriteriaQueryTest.java (working copy)
@@ -613,6 +613,7 @@
)
.addOrder( Order.desc("studentName") )
.setResultTransformer( Transformers.aliasToBean(StudentDTO.class) )
+ .setCacheable( true )
.list();
assertEquals(2, resultWithAliasedBean.size());
--
This message is automatically generated by JIRA.
-
If you think it was sent incorrectly contact one of the administrators: http://opensource.atlassian.com/projects/hibernate/secure/Administrators....
-
For more information on JIRA, see: http://www.atlassian.com/software/jira
13 years, 8 months
- 4
- 14