[hibernate-issues] [Hibernate-JIRA] Commented: (HHH-2391) ManyToMany+FetchMode.SUBSELECT+2nd level cache= NPE
Stefan (JIRA)
noreply at atlassian.com
Fri Apr 11 03:30:34 EDT 2008
[ http://opensource.atlassian.com/projects/hibernate/browse/HHH-2391?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel#action_29987 ]
Stefan commented on HHH-2391:
-----------------------------
I should clarify that this only happens for a one-to-many association with a join table, i.e. like a many-to-many association.
Stefan
> ManyToMany+FetchMode.SUBSELECT+2nd level cache= NPE
> ---------------------------------------------------
>
> Key: HHH-2391
> URL: http://opensource.atlassian.com/projects/hibernate/browse/HHH-2391
> Project: Hibernate3
> Issue Type: Bug
> Components: core
> Affects 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.jspa
-
For more information on JIRA, see: http://www.atlassian.com/software/jira
More information about the hibernate-issues
mailing list