Query.uniqueResult() returns proxied object

cbredesen · **Posted:** Tue Jul 19, 2005 9:11 am

I'm running an HQL query for the below entity. In a JUnit test, the entity is returned normally. In one of my business calls (to the same method, hence same HQL), it returns a proxied version of the entity (see debug log at the bottom).

I recently switched to H3, and I am aware that all my entities are lazy by default, however I have never seen a proxy returned by a query against the actual type (i.e., not via indirection).

My HQL query was not set as cacheable, so it should not be returning a cached copy (is this a valid assumption in H3?), but based on the log it seems that it is doing just that (and of course I see the returned copy has EnhancerByCGLIB in the type name).

The ill effect of all this is that this particular entity must live past the session and as such must be completely hydrated (I need hashCode() to function).

Any direction here is greatly appreciated (and will be rated if useful). It may be worth noting that transaction semanticse may be slightly different in the 2 use cases, but I don't see how that would affect how these items are returned.

-Chris

Hibernate version:
3.0.5 (under Spring 1.2.2)

Name and version of the database you are using:
Oracle 8i

Code:

Code:

final String hql = "from " + beanType.getName() + " this where this.code = ?";
Query query = session.createQuery(hql);
query.setString(0, code);
return query.uniqueResult();

Mapping documents:

Code:

<?xml version="1.0" encoding="UTF-8"?>

<!DOCTYPE hibernate-mapping PUBLIC
    "-//Hibernate/Hibernate Mapping DTD 3.0//EN" 
    "http://hibernate.sourceforge.net/hibernate-mapping-3.0.dtd">

<hibernate-mapping>
   <class name="com.comerxia.core.model.Merchant" table="MERCHANT">
      <cache usage="read-write" />

      <id name="id" column="ID" type="java.lang.Long">
         <generator class="sequence">
            <param name="sequence">MERCHANT_SEQ</param>
         </generator>
      </id>

      <property name="code" type="java.lang.String" update="true"
         insert="true" column="CODE" length="100" not-null="true"
         unique="true" />

      <property name="description" type="java.lang.String"
         update="true" insert="true" column="DESCRIPTION" length="100"
         not-null="true" />

      <property name="legacySiteId" type="java.lang.Long"
         update="true" insert="true" column="LEGACYSITEID" unique="true" />

      <many-to-one name="merchantGroup"
         class="com.comerxia.core.model.MerchantGroup" cascade="none"
         outer-join="auto" update="true" insert="true"
         foreign-key="MERCHANT_MERCHANTGROUPID_FK" column="MERCHANTGROUPID"
         not-null="true" />

      <set name="users" table="LINKMERCHANTIDCUSER" lazy="true"
         cascade="none" sort="unsorted">

         <key column="MERCHANTID" foreign-key="LMIU_MERCHANTID_FK">
         </key>

         <many-to-many class="com.comerxia.core.model.User"
            column="IDCUSERID" outer-join="auto"
            foreign-key="LMIU_IDCUSERID_FK" />

      </set>

      <property name="legacyCobrandId" type="java.lang.Long"
         update="true" insert="true" column="LEGACYCOBRANDID" unique="true" />

      <property name="enabled" type="java.lang.Boolean" update="true"
         insert="true" column="ENABLEDFLAG" not-null="true" />

      <property name="webServiceKey" type="java.lang.String"
         update="true" insert="true" column="WEBSERVICEKEY" length="50" />

      <set name="warehouseAddresses" table="LINKMERCHANTADDRESS"
         lazy="true" cascade="save-update" sort="unsorted">

         <key column="MERCHANTID" foreign-key="LMA_MERCHANTID_FK">
         </key>

         <many-to-many
            class="com.comerxia.core.model.WarehouseAddress" column="ADDRESSID"
            outer-join="auto" foreign-key="LMA_ADDRESSID_FK" />

      </set>

      <property name="webServiceUserId" type="java.lang.Long"
         update="true" insert="true" column="WEBSERVICEUSERID" unique="true" />

      <many-to-one name="returnsAddress"
         class="com.comerxia.core.model.WarehouseAddress" cascade="none"
         outer-join="auto" update="true" insert="true"
         foreign-key="MERCHANT_RETURNSADDRESSID_FK" column="RETURNSADDRESSID" />

      <property name="dateCreated" type="java.util.Date"
         update="false" insert="false" column="DATECREATED" />

   </class>

</hibernate-mapping>

Debug level Hibernate log excerpt:

Code:

2005-07-18 16:27:03,631 DEBUG [main] impl.SessionImpl (SessionImpl.java:829) - find: from com.comerxia.core.model.Merchant this where this.code = ?
2005-07-18 16:27:03,631 DEBUG [main] engine.QueryParameters (QueryParameters.java:221) - parameters: [AMAZON]
2005-07-18 16:27:03,631 DEBUG [main] engine.QueryParameters (QueryParameters.java:224) - named parameters: {}
2005-07-18 16:27:03,647 DEBUG [main] ast.QueryTranslatorImpl (QueryTranslatorImpl.java:207) - parse() - HQL: from com.comerxia.core.model.Merchant this where this.code = ?
2005-07-18 16:27:03,663 DEBUG [main] ast.QueryTranslatorImpl (QueryTranslatorImpl.java:223) - --- HQL AST ---
 \-[QUERY] 'query'
    +-[SELECT_FROM] 'SELECT_FROM'
    |  \-[FROM] 'from'
    |     \-[RANGE] 'RANGE'
    |        +-[DOT] '.'
    |        |  +-[DOT] '.'
    |        |  |  +-[DOT] '.'
    |        |  |  |  +-[DOT] '.'
    |        |  |  |  |  +-[IDENT] 'com'
    |        |  |  |  |  \-[IDENT] 'comerxia'
    |        |  |  |  \-[IDENT] 'core'
    |        |  |  \-[IDENT] 'model'
    |        |  \-[IDENT] 'Merchant'
    |        \-[ALIAS] 'this'
    \-[WHERE] 'where'
       \-[EQ] '='
          +-[DOT] '.'
          |  +-[IDENT] 'this'
          |  \-[IDENT] 'code'
          \-[PARAM] '?'

2005-07-18 16:27:03,678 DEBUG [main] ast.ErrorCounter (ErrorCounter.java:72) - throwQueryException() : no errors
2005-07-18 16:27:03,678 DEBUG [main] antlr.HqlSqlBaseWalker (HqlSqlBaseWalker.java:120) - query() << begin, level = 1
2005-07-18 16:27:03,694 DEBUG [main] ast.FromElement (FromElement.java:88) - FromClause{level=1} :  com.comerxia.core.model.Merchant (this) -> merchant0_
2005-07-18 16:27:03,709 DEBUG [main] ast.FromReferenceNode (FromReferenceNode.java:48) - Resolved :  this -> merchant0_.ID
2005-07-18 16:27:03,725 DEBUG [main] ast.DotNode (DotNode.java:476) - getDataType() : code -> org.hibernate.type.StringType@18b492
2005-07-18 16:27:03,725 DEBUG [main] ast.FromReferenceNode (FromReferenceNode.java:48) - Resolved :  this.code -> merchant0_.CODE
2005-07-18 16:27:03,741 DEBUG [main] antlr.HqlSqlBaseWalker (HqlSqlBaseWalker.java:125) - query() : finishing up , level = 1
2005-07-18 16:27:03,741 DEBUG [main] ast.HqlSqlWalker (HqlSqlWalker.java:331) - processQuery() :  ( SELECT ( FromClause{level=1} CORE.MERCHANT merchant0_ ) ( where ( = ( merchant0_.CODE merchant0_.ID code ) ? ) ) )
2005-07-18 16:27:03,756 DEBUG [main] ast.HqlSqlWalker (HqlSqlWalker.java:451) - Derived SELECT clause created.
2005-07-18 16:27:03,756 DEBUG [main] ast.JoinProcessor (JoinProcessor.java:112) - Using FROM fragment [CORE.MERCHANT merchant0_]
2005-07-18 16:27:03,772 DEBUG [main] antlr.HqlSqlBaseWalker (HqlSqlBaseWalker.java:128) - query() >> end, level = 1
2005-07-18 16:27:03,788 DEBUG [main] ast.QueryTranslatorImpl (QueryTranslatorImpl.java:193) - --- SQL AST ---
 \-[SELECT] QueryNode: 'SELECT'  querySpaces (CORE.MERCHANT)
    +-[SELECT_CLAUSE] SelectClause: '{derived select clause}'
    |  +-[SELECT_EXPR] SelectExpressionImpl: 'merchant0_.ID as ID' {FromElement{explicit,not a collection join,not a fetch join,fetch non-lazy properties,classAlias=this,role=null,tableName=CORE.MERCHANT,tableAlias=merchant0_,colums={,className=com.comerxia.core.model.Merchant}}}
    |  \-[SQL_TOKEN] SqlFragment: 'merchant0_.CODE as CODE21_, merchant0_.DESCRIPTION as DESCRIPT3_21_, merchant0_.LEGACYSITEID as LEGACYSI4_21_, merchant0_.MERCHANTGROUPID as MERCHANT5_21_, merchant0_.LEGACYCOBRANDID as LEGACYCO6_21_, merchant0_.ENABLEDFLAG as ENABLEDF7_21_, merchant0_.WEBSERVICEKEY as WEBSERVI8_21_, merchant0_.WEBSERVICEUSERID as WEBSERVI9_21_, merchant0_.RETURNSADDRESSID as RETURNS10_21_, merchant0_.DATECREATED as DATECRE11_21_'
    +-[FROM] FromClause: 'from' FromClause{level=1, fromElementCounter=1, fromElements=1, fromElementByClassAlias=[this], fromElementByTableAlias=[merchant0_], fromElementsByPath=[], collectionJoinFromElementsByPath=[], impliedElements=[]}
    |  \-[FROM_FRAGMENT] FromElement: 'CORE.MERCHANT merchant0_' FromElement{explicit,not a collection join,not a fetch join,fetch non-lazy properties,classAlias=this,role=null,tableName=CORE.MERCHANT,tableAlias=merchant0_,colums={,className=com.comerxia.core.model.Merchant}}
    \-[WHERE] SqlNode: 'where'
       \-[EQ] SqlNode: '='
          +-[DOT] DotNode: 'merchant0_.CODE' {propertyName=code,dereferenceType=4,propertyPath=code,path=this.code,tableAlias=merchant0_,className=com.comerxia.core.model.Merchant,classAlias=this}
          |  +-[ALIAS_REF] IdentNode: 'merchant0_.ID' {alias=this, className=com.comerxia.core.model.Merchant, tableAlias=merchant0_}
          |  \-[IDENT] IdentNode: 'code' {originalText=code}
          \-[PARAM] SqlNode: '?'

2005-07-18 16:27:03,788 DEBUG [main] ast.ErrorCounter (ErrorCounter.java:72) - throwQueryException() : no errors
2005-07-18 16:27:03,803 DEBUG [main] ast.QueryTranslatorImpl (QueryTranslatorImpl.java:177) - HQL: from com.comerxia.core.model.Merchant this where this.code = ?
2005-07-18 16:27:03,803 DEBUG [main] ast.QueryTranslatorImpl (QueryTranslatorImpl.java:178) - SQL: select merchant0_.ID as ID, merchant0_.CODE as CODE21_, merchant0_.DESCRIPTION as DESCRIPT3_21_, merchant0_.LEGACYSITEID as LEGACYSI4_21_, merchant0_.MERCHANTGROUPID as MERCHANT5_21_, merchant0_.LEGACYCOBRANDID as LEGACYCO6_21_, merchant0_.ENABLEDFLAG as ENABLEDF7_21_, merchant0_.WEBSERVICEKEY as WEBSERVI8_21_, merchant0_.WEBSERVICEUSERID as WEBSERVI9_21_, merchant0_.RETURNSADDRESSID as RETURNS10_21_, merchant0_.DATECREATED as DATECRE11_21_ from CORE.MERCHANT merchant0_ where merchant0_.CODE=?
2005-07-18 16:27:03,819 DEBUG [main] ast.ErrorCounter (ErrorCounter.java:72) - throwQueryException() : no errors
2005-07-18 16:27:03,834 DEBUG [main] def.AbstractFlushingEventListener (AbstractFlushingEventListener.java:52) - flushing session
2005-07-18 16:27:03,834 DEBUG [main] def.AbstractFlushingEventListener (AbstractFlushingEventListener.java:102) - processing flush-time cascades
2005-07-18 16:27:03,850 DEBUG [main] engine.Cascades (Cascades.java:836) - processing cascade ACTION_SAVE_UPDATE for: com.comerxia.core.model.Merchant
2005-07-18 16:27:03,866 DEBUG [main] engine.Cascades (Cascades.java:890) - cascade ACTION_SAVE_UPDATE for collection: com.comerxia.core.model.Merchant.warehouseAddresses
2005-07-18 16:27:03,866 DEBUG [main] engine.Cascades (Cascades.java:908) - done cascade ACTION_SAVE_UPDATE for collection: com.comerxia.core.model.Merchant.warehouseAddresses
2005-07-18 16:27:03,881 DEBUG [main] engine.Cascades (Cascades.java:861) - done processing cascade ACTION_SAVE_UPDATE for: com.comerxia.core.model.Merchant
2005-07-18 16:27:03,881 DEBUG [main] engine.Cascades (Cascades.java:836) - processing cascade ACTION_SAVE_UPDATE for: com.comerxia.core.model.MerchantGroup
2005-07-18 16:27:03,881 DEBUG [main] engine.Cascades$5 (Cascades.java:153) - cascading to saveOrUpdate: com.comerxia.core.model.PaymentMethod
2005-07-18 16:27:03,913 DEBUG [main] def.DefaultSaveOrUpdateEventListener (DefaultSaveOrUpdateEventListener.java:58) - reassociated uninitialized proxya
2005-07-18 16:27:03,913 DEBUG [main] engine.Cascades (Cascades.java:861) - done processing cascade ACTION_SAVE_UPDATE for: com.comerxia.core.model.MerchantGroup
2005-07-18 16:27:03,928 DEBUG [main] def.AbstractFlushingEventListener (AbstractFlushingEventListener.java:150) - dirty checking collections
2005-07-18 16:27:03,928 DEBUG [main] def.AbstractFlushingEventListener (AbstractFlushingEventListener.java:167) - Flushing entities and processing referenced collections
2005-07-18 16:27:04,006 DEBUG [main] engine.Collections (Collections.java:140) - Collection found: [com.comerxia.core.model.User.roles#282], was: [com.comerxia.core.model.User.roles#282] (initialized)
2005-07-18 16:27:04,006 DEBUG [main] engine.Collections (Collections.java:140) - Collection found: [com.comerxia.core.model.User.merchants#282], was: [com.comerxia.core.model.User.merchants#282] (initialized)
2005-07-18 16:27:04,022 DEBUG [main] engine.Collections (Collections.java:140) - Collection found: [com.comerxia.core.model.Merchant.users#61], was: [com.comerxia.core.model.Merchant.users#61] (uninitialized)
2005-07-18 16:27:04,022 DEBUG [main] engine.Collections (Collections.java:140) - Collection found: [com.comerxia.core.model.Merchant.warehouseAddresses#61], was: [com.comerxia.core.model.Merchant.warehouseAddresses#61] (uninitialized)
2005-07-18 16:27:04,038 DEBUG [main] engine.Collections (Collections.java:140) - Collection found: [com.comerxia.core.model.MerchantGroup.merchants#1], was: [com.comerxia.core.model.MerchantGroup.merchants#1] (uninitialized)
2005-07-18 16:27:04,038 DEBUG [main] def.AbstractFlushingEventListener (AbstractFlushingEventListener.java:203) - Processing unreferenced collections
2005-07-18 16:27:04,053 DEBUG [main] def.AbstractFlushingEventListener (AbstractFlushingEventListener.java:217) - Scheduling collection removes/(re)creates/updates
2005-07-18 16:27:04,053 DEBUG [main] def.AbstractFlushingEventListener (AbstractFlushingEventListener.java:79) - Flushed: 0 insertions, 0 updates, 0 deletions to 3 objects
2005-07-18 16:27:04,069 DEBUG [main] def.AbstractFlushingEventListener (AbstractFlushingEventListener.java:85) - Flushed: 0 (re)creations, 0 updates, 0 removals to 5 collections
2005-07-18 16:27:04,069 DEBUG [main] pretty.Printer (Printer.java:83) - listing entities:
2005-07-18 16:27:04,084 DEBUG [main] pretty.Printer (Printer.java:90) - com.comerxia.core.model.MerchantGroup{code=COMERXIA, enabled=true, description=Comerxia Group1, merchants=<uninitialized>, dateCreated=2005-04-07 16:04:35, fulfillmentPaymentMethod=com.comerxia.core.model.PaymentMethod#217, id=1, customerContactAllowed=true}
2005-07-18 16:27:04,084 DEBUG [main] pretty.Printer (Printer.java:90) - com.comerxia.core.model.Merchant{webServiceUserId=131, returnsAddress=null, merchantGroup=com.comerxia.core.model.MerchantGroup#1, dateCreated=2005-04-07 16:43:45, id=61, warehouseAddresses=<uninitialized>, code=AMAZON, enabled=true, users=<uninitialized>, description=Amazon.com, legacySiteId=101, webServiceKey=101, legacyCobrandId=6300}
2005-07-18 16:27:04,100 DEBUG [main] pretty.Printer (Printer.java:90) - com.comerxia.core.model.User{password=amazon, enabled=true, description=Amazon Test User, username=AMAZON, merchants=[com.comerxia.core.model.Merchant#61], roles=[], dateCreated=2005-06-23 11:26:35, id=282}
2005-07-18 16:27:04,100 DEBUG [main] def.DefaultAutoFlushEventListener (DefaultAutoFlushEventListener.java:60) - Dont need to execute flush
2005-07-18 16:27:04,116 DEBUG [main] jdbc.AbstractBatcher (AbstractBatcher.java:290) - about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
2005-07-18 16:27:04,116 DEBUG [main] jdbc.AbstractBatcher (AbstractBatcher.java:324) - select merchant0_.ID as ID, merchant0_.CODE as CODE21_, merchant0_.DESCRIPTION as DESCRIPT3_21_, merchant0_.LEGACYSITEID as LEGACYSI4_21_, merchant0_.MERCHANTGROUPID as MERCHANT5_21_, merchant0_.LEGACYCOBRANDID as LEGACYCO6_21_, merchant0_.ENABLEDFLAG as ENABLEDF7_21_, merchant0_.WEBSERVICEKEY as WEBSERVI8_21_, merchant0_.WEBSERVICEUSERID as WEBSERVI9_21_, merchant0_.RETURNSADDRESSID as RETURNS10_21_, merchant0_.DATECREATED as DATECRE11_21_ from CORE.MERCHANT merchant0_ where merchant0_.CODE=?
Hibernate: select merchant0_.ID as ID, merchant0_.CODE as CODE21_, merchant0_.DESCRIPTION as DESCRIPT3_21_, merchant0_.LEGACYSITEID as LEGACYSI4_21_, merchant0_.MERCHANTGROUPID as MERCHANT5_21_, merchant0_.LEGACYCOBRANDID as LEGACYCO6_21_, merchant0_.ENABLEDFLAG as ENABLEDF7_21_, merchant0_.WEBSERVICEKEY as WEBSERVI8_21_, merchant0_.WEBSERVICEUSERID as WEBSERVI9_21_, merchant0_.RETURNSADDRESSID as RETURNS10_21_, merchant0_.DATECREATED as DATECRE11_21_ from CORE.MERCHANT merchant0_ where merchant0_.CODE=?
2005-07-18 16:27:04,116 DEBUG [main] jdbc.AbstractBatcher (AbstractBatcher.java:378) - preparing statement
2005-07-18 16:27:04,131 DEBUG [main] type.NullableType (NullableType.java:59) - binding 'AMAZON' to parameter: 1
2005-07-18 16:27:04,163 DEBUG [main] jdbc.AbstractBatcher (AbstractBatcher.java:306) - about to open ResultSet (open ResultSets: 0, globally: 0)
2005-07-18 16:27:04,178 DEBUG [main] loader.Loader (Loader.java:405) - processing result set
2005-07-18 16:27:04,178 DEBUG [main] loader.Loader (Loader.java:410) - result set row: 0
2005-07-18 16:27:04,178 DEBUG [main] type.NullableType (NullableType.java:86) - returning '61' as column: ID
2005-07-18 16:27:04,194 DEBUG [main] loader.Loader (Loader.java:828) - result row: EntityKey[com.comerxia.core.model.Merchant#61]
2005-07-18 16:27:04,194 DEBUG [main] loader.Loader (Loader.java:429) - done processing result set (1 rows)
2005-07-18 16:27:04,209 DEBUG [main] jdbc.AbstractBatcher (AbstractBatcher.java:313) - about to close ResultSet (open ResultSets: 1, globally: 1)
2005-07-18 16:27:04,209 DEBUG [main] jdbc.AbstractBatcher (AbstractBatcher.java:298) - about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
2005-07-18 16:27:04,225 DEBUG [main] jdbc.AbstractBatcher (AbstractBatcher.java:416) - closing statement
2005-07-18 16:27:04,225 DEBUG [main] loader.Loader (Loader.java:528) - total objects hydrated: 0
2005-07-18 16:27:04,241 DEBUG [main] engine.PersistenceContext (PersistenceContext.java:789) - initializing non-lazy collections
2005-07-18 16:27:04,256 DEBUG [main] jdbc.JDBCContext (JDBCContext.java:322) - after autocommit
2005-07-18 16:27:04,256 DEBUG [main] impl.SessionImpl (SessionImpl.java:403) - after transaction completion
2005-07-18 16:27:04,272 DEBUG [main] impl.SessionImpl (SessionImpl.java:403) - after transaction completion

cbredesen · **Posted:** Tue Jul 19, 2005 1:38 pm

Somehow I missed the part of the FM that states "If the class is mapped with a proxy, load() just returns an uninitialized proxy and does not actually hit the database until you invoke a method of the proxy." Shame on me.

This seems like silly behavior, but at least it is explainable. Thanks to anyone who read this and was pondering a solution :)

emmanuel · **Posted:** Tue Jul 19, 2005 1:57 pm

To clarify this thread,
If the class is lazy,
.uniqueResult() returns an initialized object.
load() don't => this is useful to do a child.setParent() operation wo having to initialize the parent object.

gavin · **Posted:** Tue Jul 19, 2005 2:01 pm

This unit test should clarify the behavior:

Code:

   public void testInitProxy() {
      Session s = openSession();
      Transaction t = s.beginTransaction();
      Mammal plat = new Mammal();
      plat.setBodyWeight( 11f );
      plat.setDescription( "Platypus" );
      s.persist( plat );
      s.flush();
      s.clear();
      plat = (Mammal) s.load(Mammal.class, plat.getId() );
      assertFalse( Hibernate.isInitialized(plat) );
      Object plat2 = s.createQuery("from Animal a").uniqueResult();
      assertSame(plat, plat2);
      assertTrue( Hibernate.isInitialized(plat) );
      s.delete(plat);
      t.commit();
      s.close();
   }

P.S. Calling things "silly" just because you don't understand them is an excellent way to look foolish.

cbredesen · **Posted:** Tue Jul 19, 2005 2:01 pm

Actually both my use cases are calling HQL, one returns a proxy and one returns the actual object. My little revelation above explained some other things, but not this. Apologies for derailing the discussion. Here is another debug log, this one results in a non-proxied entity:

Code:

2005-07-18 16:38:01,772 DEBUG [main] impl.SessionImpl (SessionImpl.java:829) - find: from com.comerxia.core.model.Merchant this where this.code = ?
2005-07-18 16:38:01,788 DEBUG [main] engine.QueryParameters (QueryParameters.java:221) - parameters: [AMAZON]
2005-07-18 16:38:01,788 DEBUG [main] engine.QueryParameters (QueryParameters.java:224) - named parameters: {}
2005-07-18 16:38:01,803 DEBUG [main] ast.QueryTranslatorImpl (QueryTranslatorImpl.java:207) - parse() - HQL: from com.comerxia.core.model.Merchant this where this.code = ?
2005-07-18 16:38:01,819 DEBUG [main] ast.QueryTranslatorImpl (QueryTranslatorImpl.java:223) - --- HQL AST ---
 \-[QUERY] 'query'
    +-[SELECT_FROM] 'SELECT_FROM'
    |  \-[FROM] 'from'
    |     \-[RANGE] 'RANGE'
    |        +-[DOT] '.'
    |        |  +-[DOT] '.'
    |        |  |  +-[DOT] '.'
    |        |  |  |  +-[DOT] '.'
    |        |  |  |  |  +-[IDENT] 'com'
    |        |  |  |  |  \-[IDENT] 'comerxia'
    |        |  |  |  \-[IDENT] 'core'
    |        |  |  \-[IDENT] 'model'
    |        |  \-[IDENT] 'Merchant'
    |        \-[ALIAS] 'this'
    \-[WHERE] 'where'
       \-[EQ] '='
          +-[DOT] '.'
          |  +-[IDENT] 'this'
          |  \-[IDENT] 'code'
          \-[PARAM] '?'

2005-07-18 16:38:01,819 DEBUG [main] ast.ErrorCounter (ErrorCounter.java:72) - throwQueryException() : no errors
2005-07-18 16:38:01,834 DEBUG [main] antlr.HqlSqlBaseWalker (HqlSqlBaseWalker.java:120) - query() << begin, level = 1
2005-07-18 16:38:01,834 DEBUG [main] ast.FromElement (FromElement.java:88) - FromClause{level=1} :  com.comerxia.core.model.Merchant (this) -> merchant0_
2005-07-18 16:38:01,850 DEBUG [main] ast.FromReferenceNode (FromReferenceNode.java:48) - Resolved :  this -> merchant0_.ID
2005-07-18 16:38:01,866 DEBUG [main] ast.DotNode (DotNode.java:476) - getDataType() : code -> org.hibernate.type.StringType@145c414
2005-07-18 16:38:01,866 DEBUG [main] ast.FromReferenceNode (FromReferenceNode.java:48) - Resolved :  this.code -> merchant0_.CODE
2005-07-18 16:38:01,881 DEBUG [main] antlr.HqlSqlBaseWalker (HqlSqlBaseWalker.java:125) - query() : finishing up , level = 1
2005-07-18 16:38:01,897 DEBUG [main] ast.HqlSqlWalker (HqlSqlWalker.java:331) - processQuery() :  ( SELECT ( FromClause{level=1} CORE.MERCHANT merchant0_ ) ( where ( = ( merchant0_.CODE merchant0_.ID code ) ? ) ) )
2005-07-18 16:38:01,897 DEBUG [main] ast.HqlSqlWalker (HqlSqlWalker.java:451) - Derived SELECT clause created.
2005-07-18 16:38:01,913 DEBUG [main] ast.JoinProcessor (JoinProcessor.java:112) - Using FROM fragment [CORE.MERCHANT merchant0_]
2005-07-18 16:38:01,913 DEBUG [main] antlr.HqlSqlBaseWalker (HqlSqlBaseWalker.java:128) - query() >> end, level = 1
2005-07-18 16:38:01,928 DEBUG [main] ast.QueryTranslatorImpl (QueryTranslatorImpl.java:193) - --- SQL AST ---
 \-[SELECT] QueryNode: 'SELECT'  querySpaces (CORE.MERCHANT)
    +-[SELECT_CLAUSE] SelectClause: '{derived select clause}'
    |  +-[SELECT_EXPR] SelectExpressionImpl: 'merchant0_.ID as ID' {FromElement{explicit,not a collection join,not a fetch join,fetch non-lazy properties,classAlias=this,role=null,tableName=CORE.MERCHANT,tableAlias=merchant0_,colums={,className=com.comerxia.core.model.Merchant}}}
    |  \-[SQL_TOKEN] SqlFragment: 'merchant0_.CODE as CODE21_, merchant0_.DESCRIPTION as DESCRIPT3_21_, merchant0_.LEGACYSITEID as LEGACYSI4_21_, merchant0_.MERCHANTGROUPID as MERCHANT5_21_, merchant0_.LEGACYCOBRANDID as LEGACYCO6_21_, merchant0_.ENABLEDFLAG as ENABLEDF7_21_, merchant0_.WEBSERVICEKEY as WEBSERVI8_21_, merchant0_.WEBSERVICEUSERID as WEBSERVI9_21_, merchant0_.RETURNSADDRESSID as RETURNS10_21_, merchant0_.DATECREATED as DATECRE11_21_'
    +-[FROM] FromClause: 'from' FromClause{level=1, fromElementCounter=1, fromElements=1, fromElementByClassAlias=[this], fromElementByTableAlias=[merchant0_], fromElementsByPath=[], collectionJoinFromElementsByPath=[], impliedElements=[]}
    |  \-[FROM_FRAGMENT] FromElement: 'CORE.MERCHANT merchant0_' FromElement{explicit,not a collection join,not a fetch join,fetch non-lazy properties,classAlias=this,role=null,tableName=CORE.MERCHANT,tableAlias=merchant0_,colums={,className=com.comerxia.core.model.Merchant}}
    \-[WHERE] SqlNode: 'where'
       \-[EQ] SqlNode: '='
          +-[DOT] DotNode: 'merchant0_.CODE' {propertyName=code,dereferenceType=4,propertyPath=code,path=this.code,tableAlias=merchant0_,className=com.comerxia.core.model.Merchant,classAlias=this}
          |  +-[ALIAS_REF] IdentNode: 'merchant0_.ID' {alias=this, className=com.comerxia.core.model.Merchant, tableAlias=merchant0_}
          |  \-[IDENT] IdentNode: 'code' {originalText=code}
          \-[PARAM] SqlNode: '?'

2005-07-18 16:38:01,944 DEBUG [main] ast.ErrorCounter (ErrorCounter.java:72) - throwQueryException() : no errors
2005-07-18 16:38:01,944 DEBUG [main] ast.QueryTranslatorImpl (QueryTranslatorImpl.java:177) - HQL: from com.comerxia.core.model.Merchant this where this.code = ?
2005-07-18 16:38:01,959 DEBUG [main] ast.QueryTranslatorImpl (QueryTranslatorImpl.java:178) - SQL: select merchant0_.ID as ID, merchant0_.CODE as CODE21_, merchant0_.DESCRIPTION as DESCRIPT3_21_, merchant0_.LEGACYSITEID as LEGACYSI4_21_, merchant0_.MERCHANTGROUPID as MERCHANT5_21_, merchant0_.LEGACYCOBRANDID as LEGACYCO6_21_, merchant0_.ENABLEDFLAG as ENABLEDF7_21_, merchant0_.WEBSERVICEKEY as WEBSERVI8_21_, merchant0_.WEBSERVICEUSERID as WEBSERVI9_21_, merchant0_.RETURNSADDRESSID as RETURNS10_21_, merchant0_.DATECREATED as DATECRE11_21_ from CORE.MERCHANT merchant0_ where merchant0_.CODE=?
2005-07-18 16:38:01,975 DEBUG [main] ast.ErrorCounter (ErrorCounter.java:72) - throwQueryException() : no errors
2005-07-18 16:38:01,975 DEBUG [main] jdbc.AbstractBatcher (AbstractBatcher.java:290) - about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
2005-07-18 16:38:01,991 DEBUG [main] jdbc.ConnectionManager (ConnectionManager.java:296) - opening JDBC connection
2005-07-18 16:38:01,991 DEBUG [main] jdbc.AbstractBatcher (AbstractBatcher.java:324) - select merchant0_.ID as ID, merchant0_.CODE as CODE21_, merchant0_.DESCRIPTION as DESCRIPT3_21_, merchant0_.LEGACYSITEID as LEGACYSI4_21_, merchant0_.MERCHANTGROUPID as MERCHANT5_21_, merchant0_.LEGACYCOBRANDID as LEGACYCO6_21_, merchant0_.ENABLEDFLAG as ENABLEDF7_21_, merchant0_.WEBSERVICEKEY as WEBSERVI8_21_, merchant0_.WEBSERVICEUSERID as WEBSERVI9_21_, merchant0_.RETURNSADDRESSID as RETURNS10_21_, merchant0_.DATECREATED as DATECRE11_21_ from CORE.MERCHANT merchant0_ where merchant0_.CODE=?
Hibernate: select merchant0_.ID as ID, merchant0_.CODE as CODE21_, merchant0_.DESCRIPTION as DESCRIPT3_21_, merchant0_.LEGACYSITEID as LEGACYSI4_21_, merchant0_.MERCHANTGROUPID as MERCHANT5_21_, merchant0_.LEGACYCOBRANDID as LEGACYCO6_21_, merchant0_.ENABLEDFLAG as ENABLEDF7_21_, merchant0_.WEBSERVICEKEY as WEBSERVI8_21_, merchant0_.WEBSERVICEUSERID as WEBSERVI9_21_, merchant0_.RETURNSADDRESSID as RETURNS10_21_, merchant0_.DATECREATED as DATECRE11_21_ from CORE.MERCHANT merchant0_ where merchant0_.CODE=?
2005-07-18 16:38:02,006 DEBUG [main] jdbc.AbstractBatcher (AbstractBatcher.java:378) - preparing statement
2005-07-18 16:38:02,022 DEBUG [main] type.NullableType (NullableType.java:59) - binding 'AMAZON' to parameter: 1
2005-07-18 16:38:02,038 DEBUG [main] jdbc.AbstractBatcher (AbstractBatcher.java:306) - about to open ResultSet (open ResultSets: 0, globally: 0)
2005-07-18 16:38:02,038 DEBUG [main] loader.Loader (Loader.java:405) - processing result set
2005-07-18 16:38:02,038 DEBUG [main] loader.Loader (Loader.java:410) - result set row: 0
2005-07-18 16:38:02,053 DEBUG [main] type.NullableType (NullableType.java:86) - returning '61' as column: ID
2005-07-18 16:38:02,053 DEBUG [main] loader.Loader (Loader.java:828) - result row: EntityKey[com.comerxia.core.model.Merchant#61]
2005-07-18 16:38:02,069 DEBUG [main] loader.Loader (Loader.java:978) - Initializing object from ResultSet: [com.comerxia.core.model.Merchant#61]
2005-07-18 16:38:02,084 DEBUG [main] entity.BasicEntityPersister (BasicEntityPersister.java:1651) - Hydrating entity: [com.comerxia.core.model.Merchant#61]
2005-07-18 16:38:02,084 DEBUG [main] type.NullableType (NullableType.java:86) - returning 'AMAZON' as column: CODE21_
2005-07-18 16:38:02,100 DEBUG [main] type.NullableType (NullableType.java:86) - returning 'Amazon.com' as column: DESCRIPT3_21_
2005-07-18 16:38:02,116 DEBUG [main] type.NullableType (NullableType.java:86) - returning '101' as column: LEGACYSI4_21_
2005-07-18 16:38:02,116 DEBUG [main] type.NullableType (NullableType.java:86) - returning '1' as column: MERCHANT5_21_
2005-07-18 16:38:02,131 DEBUG [main] type.NullableType (NullableType.java:86) - returning '6300' as column: LEGACYCO6_21_
2005-07-18 16:38:02,131 DEBUG [main] type.NullableType (NullableType.java:86) - returning 'true' as column: ENABLEDF7_21_
2005-07-18 16:38:02,147 DEBUG [main] type.NullableType (NullableType.java:86) - returning '101' as column: WEBSERVI8_21_
2005-07-18 16:38:02,147 DEBUG [main] type.NullableType (NullableType.java:86) - returning '131' as column: WEBSERVI9_21_
2005-07-18 16:38:02,163 DEBUG [main] type.NullableType (NullableType.java:80) - returning null as column: RETURNS10_21_
2005-07-18 16:38:02,194 DEBUG [main] type.NullableType (NullableType.java:86) - returning '2005-04-07 16:43:45' as column: DATECRE11_21_
2005-07-18 16:38:02,209 DEBUG [main] loader.Loader (Loader.java:429) - done processing result set (1 rows)
2005-07-18 16:38:02,209 DEBUG [main] jdbc.AbstractBatcher (AbstractBatcher.java:313) - about to close ResultSet (open ResultSets: 1, globally: 1)
2005-07-18 16:38:02,209 DEBUG [main] jdbc.AbstractBatcher (AbstractBatcher.java:298) - about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
2005-07-18 16:38:02,225 DEBUG [main] jdbc.AbstractBatcher (AbstractBatcher.java:416) - closing statement
2005-07-18 16:38:02,225 DEBUG [main] loader.Loader (Loader.java:528) - total objects hydrated: 1
2005-07-18 16:38:02,241 DEBUG [main] engine.TwoPhaseLoad (TwoPhaseLoad.java:96) - resolving associations for [com.comerxia.core.model.Merchant#61]
2005-07-18 16:38:02,256 DEBUG [main] def.DefaultLoadEventListener (DefaultLoadEventListener.java:143) - loading entity: [com.comerxia.core.model.MerchantGroup#1]
2005-07-18 16:38:02,272 DEBUG [main] def.DefaultLoadEventListener (DefaultLoadEventListener.java:216) - creating new proxy for entity
2005-07-18 16:38:02,288 DEBUG [main] engine.CollectionLoadContext (CollectionLoadContext.java:141) - creating collection wrapper:[com.comerxia.core.model.Merchant.users#61]
2005-07-18 16:38:02,288 DEBUG [main] engine.CollectionLoadContext (CollectionLoadContext.java:141) - creating collection wrapper:[com.comerxia.core.model.Merchant.warehouseAddresses#61]
2005-07-18 16:38:02,303 DEBUG [main] engine.TwoPhaseLoad (TwoPhaseLoad.java:119) - adding entity to second-level cache: [com.comerxia.core.model.Merchant#61]
2005-07-18 16:38:02,319 DEBUG [main] cache.ReadWriteCache (ReadWriteCache.java:148) - Caching: com.comerxia.core.model.Merchant#61
2005-07-18 16:38:02,319 DEBUG [main] cache.EhCache (EhCache.java:104) - key: com.comerxia.core.model.Merchant#61
2005-07-18 16:38:02,319 DEBUG [main] cache.EhCache (EhCache.java:113) - Element for com.comerxia.core.model.Merchant#61 is null
2005-07-18 16:38:02,334 DEBUG [main] cache.ReadWriteCache (ReadWriteCache.java:160) - Cached: com.comerxia.core.model.Merchant#61
2005-07-18 16:38:02,334 DEBUG [main] engine.TwoPhaseLoad (TwoPhaseLoad.java:167) - done materializing entity [com.comerxia.core.model.Merchant#61]
2005-07-18 16:38:02,350 DEBUG [main] engine.PersistenceContext (PersistenceContext.java:789) - initializing non-lazy collections
2005-07-18 16:38:02,350 DEBUG [main] jdbc.JDBCContext (JDBCContext.java:322) - after autocommit
2005-07-18 16:38:02,366 DEBUG [main] impl.SessionImpl (SessionImpl.java:403) - after transaction completion
2005-07-18 16:38:02,366 DEBUG [main] impl.SessionImpl (SessionImpl.java:403) - after transaction completion