Hello,
I'm running a simple HQL query to pull an object by ID. This object's class happens to be mapped with @EmbeddableSuperclass and @Entity.
The object is pulled correctly, but then immediately, Hibernate fetches the object again. This time, it uses a subclass's class names when constructing the SQL.
I don't think it's supposed to generate a second query immediately. In fact, it appears that it is loading the instance twice, once as a Person and once as a Presenter. And the second time it's almost as if Hibernate is eager fetching the second object.
Any ideas?
Thanks!
Seth
Hibernate version: 3.1rc2 + annotations 3.1b5
Mapping documents:
Code:
@EmbeddableSuperclass(access = AccessType.FIELD)
@Entity
@Table(name="people"
,catalog="jug"
, uniqueConstraints = { @UniqueConstraint( columnNames = { "id" } ) }
)
@Inheritance(
strategy=InheritanceType.SINGLE_TABLE
)
public class Person implements java.io.Serializable {
@Id(generate=GeneratorType.AUTO)
@Column(name="id", unique=true, nullable=false)
private long id;
@Embedded
private Name name;
@Version
private long version;
@ManyToMany(fetch=FetchType.LAZY,
targetEntity=Meeting.class,
cascade={CascadeType.PERSIST, CascadeType.MERGE},
mappedBy="attendees"
)
private Set<org.example.jug.Meeting> meetings;
@ManyToMany(fetch=FetchType.LAZY,
targetEntity=org.example.jug.Jug.class,
cascade={CascadeType.PERSIST, CascadeType.MERGE},
mappedBy="members"
)
private Set<org.example.jug.Jug> jugs;
Code:
@Entity(access=AccessType.FIELD)
@Table(name="people")
public class Presenter extends Person {
private String bio;
@OneToMany(cascade={CascadeType.ALL}, fetch=FetchType.LAZY,
mappedBy="presenter",targetEntity=Meeting.class)
private Set<Meeting> presentsAt;
Code:
Query q = session.createQuery("from org.example.jug.Person p " +
"where p.id = :id").setLong("id", personId);
return q.list().get(0);
Here's where it switches from Person (the superclass) to Presenter (the subclass). Notice how in the HQL query I'm referencing Person, and the instance I'm loading is of type Person.
Code:
2005-10-25 02:02:58,531 DEBUG [org.hibernate.hql.ast.QueryTranslatorImpl] - HQL: from org.example.jug.Person p where p.id = :id
2005-10-25 02:02:58,531 DEBUG [org.hibernate.hql.ast.QueryTranslatorImpl] - SQL: select person0_.id as id6_, person0_.first_name as first3_6_, person0_.last_name as last4_6_, person0_.middle_name as middle5_6_, person0_.version as version6_ from jug.people person0_ where person0_.id=?
2005-10-25 02:02:58,546 DEBUG [org.hibernate.hql.ast.ErrorCounter] - throwQueryException() : no errors
2005-10-25 02:02:58,546 DEBUG [org.hibernate.hql.ast.QueryTranslatorImpl] - parse() - HQL: from org.example.jug.Presenter p where p.id = :id
Here's where the object instance is created (this actually happens before the above log code:
Code:
2005-10-25 02:02:58,000 DEBUG [org.hibernate.engine.Versioning] - using initial version: 0
2005-10-25 02:02:58,015 DEBUG [org.hibernate.persister.entity.AbstractEntityPersister] - Inserting entity: org.example.jug.Person (native id)
2005-10-25 02:02:58,015 DEBUG [org.hibernate.persister.entity.AbstractEntityPersister] - Version: 0
2005-10-25 02:02:58,015 DEBUG [org.hibernate.jdbc.AbstractBatcher] - about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
2005-10-25 02:02:58,015 DEBUG [org.hibernate.SQL] - insert into jug.people (first_name, last_name, middle_name, version, TYPE) values (?, ?, ?, ?, 'org.example.jug.Person')
Hibernate: insert into jug.people (first_name, last_name, middle_name, version, TYPE) values (?, ?, ?, ?, 'org.example.jug.Person')
2005-10-25 02:02:58,015 DEBUG [org.hibernate.jdbc.AbstractBatcher] - preparing statement
2005-10-25 02:02:58,031 DEBUG [org.hibernate.persister.entity.AbstractEntityPersister] - Dehydrating entity: [org.example.jug.Person#<null>]
2005-10-25 02:02:58,031 DEBUG [org.hibernate.type.StringType] - binding 'homer' to parameter: 1
2005-10-25 02:02:58,031 DEBUG [org.hibernate.type.StringType] - binding 'simpson' to parameter: 2
2005-10-25 02:02:58,031 DEBUG [org.hibernate.type.StringType] - binding 'j' to parameter: 3
2005-10-25 02:02:58,031 DEBUG [org.hibernate.type.LongType] - binding '0' to parameter: 4
2005-10-25 02:02:58,031 DEBUG [org.hibernate.id.IdentifierGeneratorFactory] - Natively generated identity: 41
2005-10-25 02:02:58,031 DEBUG [org.hibernate.jdbc.AbstractBatcher] - about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
2005-10-25 02:02:58,031 DEBUG [org.hibernate.jdbc.AbstractBatcher] - closing statement
2005-10-25 02:02:58,031 DEBUG [org.hibernate.engine.Cascade] - processing cascade ACTION_SAVE_UPDATE for: org.example.jug.Person
2005-10-25 02:02:58,031 DEBUG [org.hibernate.engine.Cascade] - done processing cascade ACTION_SAVE_UPDATE for: org.example.jug.Person
2005-10-25 02:02:58,031 DEBUG [org.hibernate.transaction.JDBCTransaction] - commit
More complete log:
Code:
2005-10-25 02:02:58,281 DEBUG [org.hibernate.event.def.DefaultLoadEventListener] - loading entity: [org.example.jug.Person#41]
2005-10-25 02:02:58,281 DEBUG [org.hibernate.event.def.DefaultLoadEventListener] - attempting to resolve: [org.example.jug.Person#41]
2005-10-25 02:02:58,281 DEBUG [org.hibernate.event.def.DefaultLoadEventListener] - object not resolved in any cache: [org.example.jug.Person#41]
2005-10-25 02:02:58,281 DEBUG [org.hibernate.persister.entity.AbstractEntityPersister] - Fetching entity: [org.example.jug.Person#41]
2005-10-25 02:02:58,296 DEBUG [org.hibernate.loader.Loader] - loading entity: [org.example.jug.Person#41]
2005-10-25 02:02:58,296 DEBUG [org.hibernate.jdbc.AbstractBatcher] - about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
2005-10-25 02:02:58,296 DEBUG [org.hibernate.SQL] - select person0_.id as id6_0_, person0_.first_name as first3_6_0_, person0_.last_name as last4_6_0_, person0_.middle_name as middle5_6_0_, person0_.version as version6_0_ from jug.people person0_ where person0_.id=?
Hibernate: select person0_.id as id6_0_, person0_.first_name as first3_6_0_, person0_.last_name as last4_6_0_, person0_.middle_name as middle5_6_0_, person0_.version as version6_0_ from jug.people person0_ where person0_.id=?
2005-10-25 02:02:58,296 DEBUG [org.hibernate.jdbc.AbstractBatcher] - preparing statement
2005-10-25 02:02:58,296 DEBUG [org.hibernate.type.LongType] - binding '41' to parameter: 1
2005-10-25 02:02:58,296 DEBUG [org.hibernate.jdbc.AbstractBatcher] - about to open ResultSet (open ResultSets: 0, globally: 0)
2005-10-25 02:02:58,296 DEBUG [org.hibernate.loader.Loader] - processing result set
2005-10-25 02:02:58,296 DEBUG [org.hibernate.loader.Loader] - result set row: 0
2005-10-25 02:02:58,296 DEBUG [org.hibernate.loader.Loader] - result row: EntityKey[org.example.jug.Person#41]
2005-10-25 02:02:58,296 DEBUG [org.hibernate.loader.Loader] - Initializing object from ResultSet: [org.example.jug.Person#41]
2005-10-25 02:02:58,312 DEBUG [org.hibernate.persister.entity.AbstractEntityPersister] - Hydrating entity: [org.example.jug.Person#41]
2005-10-25 02:02:58,312 DEBUG [org.hibernate.type.StringType] - returning 'homer' as column: first3_6_0_
2005-10-25 02:02:58,312 DEBUG [org.hibernate.type.StringType] - returning 'simpson' as column: last4_6_0_
2005-10-25 02:02:58,312 DEBUG [org.hibernate.type.StringType] - returning 'j' as column: middle5_6_0_
2005-10-25 02:02:58,312 DEBUG [org.hibernate.type.LongType] - returning '0' as column: version6_0_
2005-10-25 02:02:58,312 DEBUG [org.hibernate.engine.TwoPhaseLoad] - Version: 0
2005-10-25 02:02:58,312 DEBUG [org.hibernate.loader.Loader] - done processing result set (1 rows)
2005-10-25 02:02:58,312 DEBUG [org.hibernate.jdbc.AbstractBatcher] - about to close ResultSet (open ResultSets: 1, globally: 1)
2005-10-25 02:02:58,312 DEBUG [org.hibernate.jdbc.AbstractBatcher] - about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
2005-10-25 02:02:58,312 DEBUG [org.hibernate.jdbc.AbstractBatcher] - closing statement
2005-10-25 02:02:58,312 DEBUG [org.hibernate.loader.Loader] - total objects hydrated: 1
2005-10-25 02:02:58,312 DEBUG [org.hibernate.engine.TwoPhaseLoad] - resolving associations for [org.example.jug.Person#41]
2005-10-25 02:02:58,312 DEBUG [org.hibernate.engine.CollectionLoadContext] - creating collection wrapper:[org.example.jug.Person.meetings#41]
2005-10-25 02:02:58,312 DEBUG [org.hibernate.engine.CollectionLoadContext] - creating collection wrapper:[org.example.jug.Person.jugs#41]
2005-10-25 02:02:58,312 DEBUG [org.hibernate.engine.TwoPhaseLoad] - done materializing entity [org.example.jug.Person#41]
2005-10-25 02:02:58,312 DEBUG [org.hibernate.engine.StatefulPersistenceContext] - initializing non-lazy collections
2005-10-25 02:02:58,328 DEBUG [org.hibernate.loader.Loader] - done entity load
2005-10-25 02:02:58,343 DEBUG [org.hibernate.impl.SessionImpl] - find: from org.example.jug.Person p where p.id = :id
2005-10-25 02:02:58,343 DEBUG [org.hibernate.engine.QueryParameters] - named parameters: {id=41}
2005-10-25 02:02:58,406 DEBUG [org.hibernate.hql.ast.QueryTranslatorImpl] - parse() - HQL: from org.example.jug.Person p where p.id = :id
2005-10-25 02:02:58,421 DEBUG [org.hibernate.hql.ast.AST] - --- HQL AST ---
\-[QUERY] 'query'
+-[SELECT_FROM] 'SELECT_FROM'
| \-[FROM] 'from'
| \-[RANGE] 'RANGE'
| +-[DOT] '.'
| | +-[DOT] '.'
| | | +-[DOT] '.'
| | | | +-[IDENT] 'org'
| | | | \-[IDENT] 'example'
| | | \-[IDENT] 'jug'
| | \-[IDENT] 'Person'
| \-[ALIAS] 'p'
\-[WHERE] 'where'
\-[EQ] '='
+-[DOT] '.'
| +-[IDENT] 'p'
| \-[IDENT] 'id'
\-[COLON] ':'
\-[IDENT] 'id'
2005-10-25 02:02:58,421 DEBUG [org.hibernate.hql.ast.ErrorCounter] - throwQueryException() : no errors
2005-10-25 02:02:58,468 DEBUG [org.hibernate.hql.antlr.HqlSqlBaseWalker] - select << begin [level=1, statement=select]
2005-10-25 02:02:58,484 DEBUG [org.hibernate.hql.ast.tree.FromElement] - FromClause{level=1} : org.example.jug.Person (p) -> person0_
2005-10-25 02:02:58,484 DEBUG [org.hibernate.hql.ast.tree.FromReferenceNode] - Resolved : p -> person0_.id
2005-10-25 02:02:58,500 DEBUG [org.hibernate.hql.ast.tree.DotNode] - getDataType() : id -> org.hibernate.type.LongType@12bf892
2005-10-25 02:02:58,500 DEBUG [org.hibernate.hql.ast.tree.FromReferenceNode] - Resolved : p.id -> person0_.id
2005-10-25 02:02:58,500 DEBUG [org.hibernate.hql.antlr.HqlSqlBaseWalker] - select : finishing up [level=1, statement=select]
2005-10-25 02:02:58,500 DEBUG [org.hibernate.hql.ast.HqlSqlWalker] - processQuery() : ( SELECT ( FromClause{level=1} jug.people person0_ ) ( where ( = ( person0_.id person0_.id id ) ? ) ) )
2005-10-25 02:02:58,500 DEBUG [org.hibernate.hql.ast.HqlSqlWalker] - Derived SELECT clause created.
2005-10-25 02:02:58,515 DEBUG [org.hibernate.hql.ast.util.JoinProcessor] - Using FROM fragment [jug.people person0_]
2005-10-25 02:02:58,515 DEBUG [org.hibernate.hql.antlr.HqlSqlBaseWalker] - select >> end [level=1, statement=select]
2005-10-25 02:02:58,515 DEBUG [org.hibernate.hql.ast.AST] - --- SQL AST ---
\-[SELECT] QueryNode: 'SELECT' querySpaces (jug.people)
+-[SELECT_CLAUSE] SelectClause: '{derived select clause}'
| +-[SELECT_EXPR] SelectExpressionImpl: 'person0_.id as id6_' {FromElement{explicit,not a collection join,not a fetch join,fetch non-lazy properties,classAlias=p,role=null,tableName=jug.people,tableAlias=person0_,origin=null,colums={,className=org.example.jug.Person}}}
| \-[SQL_TOKEN] SqlFragment: 'person0_.first_name as first3_6_, person0_.last_name as last4_6_, person0_.middle_name as middle5_6_, person0_.version as version6_'
+-[FROM] FromClause: 'from' FromClause{level=1, fromElementCounter=1, fromElements=1, fromElementByClassAlias=[p], fromElementByTableAlias=[person0_], fromElementsByPath=[], collectionJoinFromElementsByPath=[], impliedElements=[]}
| \-[FROM_FRAGMENT] FromElement: 'jug.people person0_' FromElement{explicit,not a collection join,not a fetch join,fetch non-lazy properties,classAlias=p,role=null,tableName=jug.people,tableAlias=person0_,origin=null,colums={,className=org.example.jug.Person}}
\-[WHERE] SqlNode: 'where'
\-[EQ] BinaryLogicOperatorNode: '='
+-[DOT] DotNode: 'person0_.id' {propertyName=id,dereferenceType=4,propertyPath=id,path=p.id,tableAlias=person0_,className=org.example.jug.Person,classAlias=p}
| +-[ALIAS_REF] IdentNode: 'person0_.id' {alias=p, className=org.example.jug.Person, tableAlias=person0_}
| \-[IDENT] IdentNode: 'id' {originalText=id}
\-[NAMED_PARAM] ParameterNode: '?'
2005-10-25 02:02:58,515 DEBUG [org.hibernate.hql.ast.ErrorCounter] - throwQueryException() : no errors
2005-10-25 02:02:58,531 DEBUG [org.hibernate.hql.ast.QueryTranslatorImpl] - HQL: from org.example.jug.Person p where p.id = :id
2005-10-25 02:02:58,531 DEBUG [org.hibernate.hql.ast.QueryTranslatorImpl] - SQL: select person0_.id as id6_, person0_.first_name as first3_6_, person0_.last_name as last4_6_, person0_.middle_name as middle5_6_, person0_.version as version6_ from jug.people person0_ where person0_.id=?
2005-10-25 02:02:58,546 DEBUG [org.hibernate.hql.ast.ErrorCounter] - throwQueryException() : no errors
2005-10-25 02:02:58,546 DEBUG [org.hibernate.hql.ast.QueryTranslatorImpl] - parse() - HQL: from org.example.jug.Presenter p where p.id = :id
2005-10-25 02:02:58,546 DEBUG [org.hibernate.hql.ast.AST] - --- HQL AST ---
\-[QUERY] 'query'
+-[SELECT_FROM] 'SELECT_FROM'
| \-[FROM] 'from'
| \-[RANGE] 'RANGE'
| +-[DOT] '.'
| | +-[DOT] '.'
| | | +-[DOT] '.'
| | | | +-[IDENT] 'org'
| | | | \-[IDENT] 'example'
| | | \-[IDENT] 'jug'
| | \-[IDENT] 'Presenter'
| \-[ALIAS] 'p'
\-[WHERE] 'where'
\-[EQ] '='
+-[DOT] '.'
| +-[IDENT] 'p'
| \-[IDENT] 'id'
\-[COLON] ':'
\-[IDENT] 'id'
2005-10-25 02:02:58,546 DEBUG [org.hibernate.hql.ast.ErrorCounter] - throwQueryException() : no errors
2005-10-25 02:02:58,546 DEBUG [org.hibernate.hql.antlr.HqlSqlBaseWalker] - select << begin [level=1, statement=select]
2005-10-25 02:02:58,546 DEBUG [org.hibernate.hql.ast.tree.FromElement] - FromClause{level=1} : org.example.jug.Presenter (p) -> presenter0_
2005-10-25 02:02:58,562 DEBUG [org.hibernate.hql.ast.tree.FromReferenceNode] - Resolved : p -> presenter0_.id
2005-10-25 02:02:58,562 DEBUG [org.hibernate.hql.ast.tree.DotNode] - getDataType() : id -> org.hibernate.type.LongType@12bf892
2005-10-25 02:02:58,562 DEBUG [org.hibernate.hql.ast.tree.FromReferenceNode] - Resolved : p.id -> presenter0_.id
2005-10-25 02:02:58,562 DEBUG [org.hibernate.hql.antlr.HqlSqlBaseWalker] - select : finishing up [level=1, statement=select]
2005-10-25 02:02:58,562 DEBUG [org.hibernate.hql.ast.HqlSqlWalker] - processQuery() : ( SELECT ( FromClause{level=1} people presenter0_ ) ( where ( = ( presenter0_.id presenter0_.id id ) ? ) ) )
2005-10-25 02:02:58,562 DEBUG [org.hibernate.hql.ast.HqlSqlWalker] - Derived SELECT clause created.
2005-10-25 02:02:58,562 DEBUG [org.hibernate.hql.ast.util.JoinProcessor] - Using FROM fragment [people presenter0_]
2005-10-25 02:02:58,562 DEBUG [org.hibernate.hql.antlr.HqlSqlBaseWalker] - select >> end [level=1, statement=select]
2005-10-25 02:02:58,562 DEBUG [org.hibernate.hql.ast.AST] - --- SQL AST ---
\-[SELECT] QueryNode: 'SELECT' querySpaces (people)
+-[SELECT_CLAUSE] SelectClause: '{derived select clause}'
| +-[SELECT_EXPR] SelectExpressionImpl: 'presenter0_.id as id7_' {FromElement{explicit,not a collection join,not a fetch join,fetch non-lazy properties,classAlias=p,role=null,tableName=people,tableAlias=presenter0_,origin=null,colums={,className=org.example.jug.Presenter}}}
| \-[SQL_TOKEN] SqlFragment: 'presenter0_.first_name as first2_7_, presenter0_.last_name as last3_7_, presenter0_.middle_name as middle4_7_, presenter0_.version as version7_, presenter0_.bio as bio7_'
+-[FROM] FromClause: 'from' FromClause{level=1, fromElementCounter=1, fromElements=1, fromElementByClassAlias=[p], fromElementByTableAlias=[presenter0_], fromElementsByPath=[], collectionJoinFromElementsByPath=[], impliedElements=[]}
| \-[FROM_FRAGMENT] FromElement: 'people presenter0_' FromElement{explicit,not a collection join,not a fetch join,fetch non-lazy properties,classAlias=p,role=null,tableName=people,tableAlias=presenter0_,origin=null,colums={,className=org.example.jug.Presenter}}
\-[WHERE] SqlNode: 'where'
\-[EQ] BinaryLogicOperatorNode: '='
+-[DOT] DotNode: 'presenter0_.id' {propertyName=id,dereferenceType=4,propertyPath=id,path=p.id,tableAlias=presenter0_,className=org.example.jug.Presenter,classAlias=p}
| +-[ALIAS_REF] IdentNode: 'presenter0_.id' {alias=p, className=org.example.jug.Presenter, tableAlias=presenter0_}
| \-[IDENT] IdentNode: 'id' {originalText=id}
\-[NAMED_PARAM] ParameterNode: '?'
2005-10-25 02:02:58,562 DEBUG [org.hibernate.hql.ast.ErrorCounter] - throwQueryException() : no errors
2005-10-25 02:02:58,562 DEBUG [org.hibernate.hql.ast.QueryTranslatorImpl] - HQL: from org.example.jug.Presenter p where p.id = :id
2005-10-25 02:02:58,562 DEBUG [org.hibernate.hql.ast.QueryTranslatorImpl] - SQL: select presenter0_.id as id7_, presenter0_.first_name as first2_7_, presenter0_.last_name as last3_7_, presenter0_.middle_name as middle4_7_, presenter0_.version as version7_, presenter0_.bio as bio7_ from people presenter0_ where presenter0_.id=?
2005-10-25 02:02:58,562 DEBUG [org.hibernate.hql.ast.ErrorCounter] - throwQueryException() : no errors
2005-10-25 02:02:58,562 DEBUG [org.hibernate.event.def.AbstractFlushingEventListener] - flushing session
2005-10-25 02:02:58,562 DEBUG [org.hibernate.event.def.AbstractFlushingEventListener] - processing flush-time cascades
2005-10-25 02:02:58,562 DEBUG [org.hibernate.engine.Cascade] - processing cascade ACTION_SAVE_UPDATE for: org.example.jug.Person
2005-10-25 02:02:58,562 DEBUG [org.hibernate.engine.Cascade] - done processing cascade ACTION_SAVE_UPDATE for: org.example.jug.Person
2005-10-25 02:02:58,562 DEBUG [org.hibernate.event.def.AbstractFlushingEventListener] - dirty checking collections
2005-10-25 02:02:58,562 DEBUG [org.hibernate.event.def.AbstractFlushingEventListener] - Flushing entities and processing referenced collections
2005-10-25 02:02:58,562 DEBUG [org.hibernate.engine.Collections] - Collection found: [org.example.jug.Person.meetings#41], was: [org.example.jug.Person.meetings#41] (uninitialized)
2005-10-25 02:02:58,562 DEBUG [org.hibernate.engine.Collections] - Collection found: [org.example.jug.Person.jugs#41], was: [org.example.jug.Person.jugs#41] (uninitialized)
2005-10-25 02:02:58,562 DEBUG [org.hibernate.event.def.AbstractFlushingEventListener] - Processing unreferenced collections
2005-10-25 02:02:58,562 DEBUG [org.hibernate.event.def.AbstractFlushingEventListener] - Scheduling collection removes/(re)creates/updates
2005-10-25 02:02:58,562 DEBUG [org.hibernate.event.def.AbstractFlushingEventListener] - Flushed: 0 insertions, 0 updates, 0 deletions to 1 objects
2005-10-25 02:02:58,562 DEBUG [org.hibernate.event.def.AbstractFlushingEventListener] - Flushed: 0 (re)creations, 0 updates, 0 removals to 2 collections
2005-10-25 02:02:58,562 DEBUG [org.hibernate.pretty.Printer] - listing entities:
2005-10-25 02:02:58,562 DEBUG [org.hibernate.pretty.Printer] - org.example.jug.Person{meetings=<uninitialized>, jugs=<uninitialized>, name=component[firstName,lastName,middleName]{middleName=j, firstName=homer, lastName=simpson}, id=41, version=0}
2005-10-25 02:02:58,562 DEBUG [org.hibernate.event.def.DefaultAutoFlushEventListener] - Dont need to execute flush
2005-10-25 02:02:58,562 DEBUG [org.hibernate.jdbc.AbstractBatcher] - about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
2005-10-25 02:02:58,562 DEBUG [org.hibernate.SQL] - select person0_.id as id6_, person0_.first_name as first3_6_, person0_.last_name as last4_6_, person0_.middle_name as middle5_6_, person0_.version as version6_ from jug.people person0_ where person0_.id=?
Hibernate: select person0_.id as id6_, person0_.first_name as first3_6_, person0_.last_name as last4_6_, person0_.middle_name as middle5_6_, person0_.version as version6_ from jug.people person0_ where person0_.id=?
2005-10-25 02:02:58,562 DEBUG [org.hibernate.jdbc.AbstractBatcher] - preparing statement
2005-10-25 02:02:58,578 DEBUG [org.hibernate.loader.Loader] - bindNamedParameters() 41 -> id [1]
2005-10-25 02:02:58,578 DEBUG [org.hibernate.type.LongType] - binding '41' to parameter: 1
2005-10-25 02:02:58,578 DEBUG [org.hibernate.jdbc.AbstractBatcher] - about to open ResultSet (open ResultSets: 0, globally: 0)
2005-10-25 02:02:58,578 DEBUG [org.hibernate.loader.Loader] - processing result set
2005-10-25 02:02:58,578 DEBUG [org.hibernate.loader.Loader] - result set row: 0
2005-10-25 02:02:58,578 DEBUG [org.hibernate.type.LongType] - returning '41' as column: id6_
2005-10-25 02:02:58,578 DEBUG [org.hibernate.loader.Loader] - result row: EntityKey[org.example.jug.Person#41]
2005-10-25 02:02:58,578 DEBUG [org.hibernate.loader.Loader] - done processing result set (1 rows)
2005-10-25 02:02:58,578 DEBUG [org.hibernate.jdbc.AbstractBatcher] - about to close ResultSet (open ResultSets: 1, globally: 1)
2005-10-25 02:02:58,578 DEBUG [org.hibernate.jdbc.AbstractBatcher] - about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
2005-10-25 02:02:58,578 DEBUG [org.hibernate.jdbc.AbstractBatcher] - closing statement
2005-10-25 02:02:58,578 DEBUG [org.hibernate.loader.Loader] - total objects hydrated: 0
2005-10-25 02:02:58,578 DEBUG [org.hibernate.engine.StatefulPersistenceContext] - initializing non-lazy collections
2005-10-25 02:02:58,578 DEBUG [org.hibernate.jdbc.AbstractBatcher] - about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
2005-10-25 02:02:58,578 DEBUG [org.hibernate.SQL] - select presenter0_.id as id7_, presenter0_.first_name as first2_7_, presenter0_.last_name as last3_7_, presenter0_.middle_name as middle4_7_, presenter0_.version as version7_, presenter0_.bio as bio7_ from people presenter0_ where presenter0_.id=?
Hibernate: select presenter0_.id as id7_, presenter0_.first_name as first2_7_, presenter0_.last_name as last3_7_, presenter0_.middle_name as middle4_7_, presenter0_.version as version7_, presenter0_.bio as bio7_ from people presenter0_ where presenter0_.id=?
2005-10-25 02:02:58,578 DEBUG [org.hibernate.jdbc.AbstractBatcher] - preparing statement
2005-10-25 02:02:58,578 DEBUG [org.hibernate.loader.Loader] - bindNamedParameters() 41 -> id [1]
2005-10-25 02:02:58,578 DEBUG [org.hibernate.type.LongType] - binding '41' to parameter: 1
2005-10-25 02:02:58,578 DEBUG [org.hibernate.jdbc.AbstractBatcher] - about to open ResultSet (open ResultSets: 0, globally: 0)
2005-10-25 02:02:58,578 DEBUG [org.hibernate.loader.Loader] - processing result set
2005-10-25 02:02:58,578 DEBUG [org.hibernate.loader.Loader] - result set row: 0
2005-10-25 02:02:58,578 DEBUG [org.hibernate.type.LongType] - returning '41' as column: id7_
2005-10-25 02:02:58,578 DEBUG [org.hibernate.loader.Loader] - result row: EntityKey[org.example.jug.Presenter#41]
2005-10-25 02:02:58,578 DEBUG [org.hibernate.loader.Loader] - Initializing object from ResultSet: [org.example.jug.Presenter#41]
2005-10-25 02:02:58,578 DEBUG [org.hibernate.persister.entity.AbstractEntityPersister] - Hydrating entity: [org.example.jug.Presenter#41]
2005-10-25 02:02:58,578 DEBUG [org.hibernate.type.StringType] - returning 'homer' as column: first2_7_
2005-10-25 02:02:58,578 DEBUG [org.hibernate.type.StringType] - returning 'simpson' as column: last3_7_
2005-10-25 02:02:58,593 DEBUG [org.hibernate.type.StringType] - returning 'j' as column: middle4_7_
2005-10-25 02:02:58,593 DEBUG [org.hibernate.type.LongType] - returning '0' as column: version7_
2005-10-25 02:02:58,593 DEBUG [org.hibernate.type.StringType] - returning null as column: bio7_
2005-10-25 02:02:58,593 DEBUG [org.hibernate.engine.TwoPhaseLoad] - Version: 0
2005-10-25 02:02:58,593 DEBUG [org.hibernate.loader.Loader] - done processing result set (1 rows)
2005-10-25 02:02:58,593 DEBUG [org.hibernate.jdbc.AbstractBatcher] - about to close ResultSet (open ResultSets: 1, globally: 1)
2005-10-25 02:02:58,593 DEBUG [org.hibernate.jdbc.AbstractBatcher] - about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
2005-10-25 02:02:58,593 DEBUG [org.hibernate.jdbc.AbstractBatcher] - closing statement
2005-10-25 02:02:58,593 DEBUG [org.hibernate.loader.Loader] - total objects hydrated: 1
2005-10-25 02:02:58,593 DEBUG [org.hibernate.engine.TwoPhaseLoad] - resolving associations for [org.example.jug.Presenter#41]
2005-10-25 02:02:58,593 DEBUG [org.hibernate.engine.CollectionLoadContext] - creating collection wrapper:[org.example.jug.Presenter.meetings#41]
2005-10-25 02:02:58,593 DEBUG [org.hibernate.engine.CollectionLoadContext] - creating collection wrapper:[org.example.jug.Presenter.jugs#41]
2005-10-25 02:02:58,593 DEBUG [org.hibernate.engine.CollectionLoadContext] - creating collection wrapper:[org.example.jug.Presenter.presentsAt#41]
2005-10-25 02:02:58,593 DEBUG [org.hibernate.engine.TwoPhaseLoad] - done materializing entity [org.example.jug.Presenter#41]
2005-10-25 02:02:58,593 DEBUG [org.hibernate.engine.StatefulPersistenceContext] - initializing non-lazy collections
2005-10-25 02:02:58,609 DEBUG [org.hibernate.event.def.AbstractFlushingEventListener] - flushing session
[/code]