-->
These old forums are deprecated now and set to read-only. We are waiting for you on our new forums!
More modern, Discourse-based and with GitHub/Google/Twitter authentication built-in.

View unanswered posts | View active topics


Board index » Hibernate & Java Persistence » Hibernate Users

All times are UTC - 5 hours [ DST ]


Forum locked This topic is locked, you cannot edit posts or make further replies.  Page 1 of 1
  [ 2 posts ] 
  Previous topic | Next topic 
Author Message
mmoores
 Post subject: one-to-many bag not hydrated when using composite fk
PostPosted: Fri Apr 13, 2007 3:19 pm 
Newbie

Joined: Tue Jan 11, 2005 6:02 pm
Posts: 13
Location: Seattle
I have a pretty simple configuration with a bag, and
one of the collections is not being filled, although the debug output
shows that hibernate is retrieving a result set.
I included mappings for three classes.
See the mapping between class ShopCartItem and ShopCartItemModifier,
and the associated debug log.

I expect ShopCartItem.modifiers to contain exactly one entry, but I end up with an empty collection. I'm also baffled as to why Hibernate executed three SQL statements for the ShopCartItemModifier bag. The end of the debug excerpt says "
2 collections were found in result set for role: com.real.scs.domain.shopcart.ShopCartItem.modifiers". What does that mean?

Thanks for taking a look it my mappings.
--Michael

Hibernate version:
3.2.2ga

Mapping documents:
Code:
<?xml version="1.0"?>
<!DOCTYPE hibernate-mapping SYSTEM
          "http://hibernate.sourceforge.net/hibernate-mapping-3.0.dtd" >

<hibernate-mapping package="com.real.scs.domain.shopcart">
<typedef name="modifierType" class="com.real.scs.hibernate.usertype.EnumUserType">
     <param name="enumClassName">com.real.scs.domain.CartModifier$ModifierType</param>
</typedef>
<class name="ShopCart" table="/*scs*/shop_carts" dynamic-update="false">
   <id name="id" type="long" column="id">
      <generator class="sequence">
         <param name="sequence">shop_cart_seq</param>
      </generator>
  </id>
  <!-- Properties -->
  <version name="version" column="version" type="com.real.scs.dao.shopcart.hibernate.usertype.ShopCartVersionUserType"/>
  <property name="shopCartGuid" column="guid" type="com.real.scs.dao.shopcart.hibernate.usertype.ShopCartGuidUserType" not-null="true"/>
  <property name="udsUserGuid" column="uds_user_guid" type="com.real.scs.dao.shopcart.hibernate.usertype.UdsUserGuidUserType"/>
  <property name="storefrontScope" column="storefront_scope" type="com.real.scs.dao.shopcart.hibernate.usertype.StorefrontScopeUserType"/>
  <property name="currencyCode" column="currency_code" type = "com.real.scs.dao.shopcart.hibernate.usertype.CodeUserType"/>
  <property name="createTime" column="create_time" update="false" not-null="true"/>
  <property name="lastModifyTime" insert="false" column="modify_time"/> 

  <bag name="items" lazy="false"
            inverse="true"
            fetch="join"
            cascade="all-delete-orphan">
      <key column="sc_id"/>
      <one-to-many class="ShopCartItem"/>
  </bag>
   <bag name="modifiers" lazy="false"
            inverse="true"
            cascade="all-delete-orphan">
      <key column="sc_id"/>
      <one-to-many class="CartModifier"/>
  </bag>
</class>
</hibernate-mapping>

<?xml version="1.0"?>
<!DOCTYPE hibernate-mapping SYSTEM
          "http://hibernate.sourceforge.net/hibernate-mapping-3.0.dtd" >
<hibernate-mapping package="com.real.scs.domain.shopcart">
<class name="ShopCartItem" table="/*scs*/shop_cart_items" dynamic-update="false">
   <composite-id unsaved-value="undefined">
      <!-- note; the ordering of key entries is important if you got child collections.
      -->
      <key-many-to-one name="shopCart" column="sc_id"/>
      <key-property name="product" column="product_id"
               type="com.real.scs.dao.shopcart.hibernate.usertype.ProductUserType"/>
   </composite-id>
  <!-- Properties -->
  <property name="quantity" column="quantity" not-null="true"/>
  <property name="productPriceCode" column="product_price_code" type="com.real.scs.dao.shopcart.hibernate.usertype.CodeUserType"/>
  <property name="serviceTermCode" column="service_term_code" type="com.real.scs.dao.shopcart.hibernate.usertype.CodeUserType"/>
  <property name="fulfillmentTypeCode" column="fulfillment_type" type="com.real.scs.dao.shopcart.hibernate.usertype.CodeUserType"/>
  <property name="productPlatformCode" column="product_platform_code" type="com.real.scs.dao.shopcart.hibernate.usertype.CodeUserType"/>
  <!-- TODO: consider making base consumer service id a modifier?
  <property name="baseConsumerServiceId" column="service_term_code" type="com.real.scs.dao.shopcart.hibernate.usertype.CodeUserType"/>
-->
  <property name="baseCalculatedPrice" column="base_calculated_price"/>
  <property name="discountCalculatedPrice" column="discount_calculated_price"/>

<bag name="modifiers" lazy="false"
            inverse="true"
            cascade="all-delete-orphan">
      <key>
          <column name="scitm_sc_id"/>
          <column name="scitm_product_id"/>
      </key>
      <one-to-many class="CartItemModifier"/>
  </bag>

  <property name="createTime" column="create_time" update="false" not-null="true"/>
  <property name="lastModifyTime" insert="false" column="modify_time"/>
</class>
</hibernate-mapping>
<?xml version="1.0"?>
<!DOCTYPE hibernate-mapping SYSTEM
          "http://hibernate.sourceforge.net/hibernate-mapping-3.0.dtd" >
<hibernate-mapping package="com.real.scs.domain.shopcart">
<class name="CartItemModifier" table="/*scs*/shop_cart_item_modifiers" dynamic-update="false">
   <composite-id unsaved-value="undefined">
      <key-many-to-one name="shopCartItem">
          <column name="scitm_sc_id" not-null="true"/>
          <column name="scitm_product_id" not-null="true"/>
      </key-many-to-one>
     <key-property name="modifierTypeCode" column="modifier_type_code"/>
   </composite-id>
   <property name="modifierValue" column="modifier_value" not-null="true"/>
   <property name="createTime" column="create_time" update="false" not-null="true"/>
   <property name="lastModifyTime" insert="false" column="modify_time"/> 
 
</class>
</hibernate-mapping>



Code between sessionFactory.openSession() and session.close():
Code:
        Session s = sessionFactory.openSession();
        log.debug("QUERY-BEGIN");
        shopCart = (ShopCart) s.get(ShopCart.class, shopCart.getId());
        assertEquals(shopCart.getShopCartItemCount() , 1);
        item = shopCart.getShopCartItemIterator().next();
        assertEquals(item.getModifierCount(), 1);
        s.close();



Name and version of the database you are using:
Oracle 10g
The generated SQL (show_sql=true):
12:08:00.268 [main] DEBUG org.hibernate.SQL - select shopcart0_.id as id0_1_, shopcart0_.version as version0_1_, shopcart0_.guid as guid0_1_, shopcart0_.uds_user_guid as uds4_0_1_, shopcart0_.storefront_scope as storefront5_0_1_, shopcart0_.currency_code as currency6_0_1_, shopcart0_.create_time as create7_0_1_, shopcart0_.modify_time as modify8_0_1_, shopcart0_.partner_code as partner9_0_1_, shopcart0_.click_path as click10_0_1_, shopcart0_.offer_page as offer11_0_1_, shopcart0_.local_source as local12_0_1_, shopcart0_.referring_source as referring13_0_1_, items1_.sc_id as sc1_3_, items1_.product_id as product2_3_, items1_.sc_id as sc1_1_0_, items1_.product_id as product2_1_0_, items1_.quantity as quantity1_0_, items1_.product_price_code as product4_1_0_, items1_.service_term_code as service5_1_0_, items1_.fulfillment_type as fulfillm6_1_0_, items1_.product_platform_code as product7_1_0_, items1_.base_calculated_price as base8_1_0_, items1_.discount_calculated_price as discount9_1_0_, items1_.partner_code as partner10_1_0_, items1_.click_path as click11_1_0_, items1_.offer_page as offer12_1_0_, items1_.local_source as local13_1_0_, items1_.referring_source as referring14_1_0_, items1_.create_time as create15_1_0_, items1_.modify_time as modify16_1_0_ from /*scs*/shop_carts shopcart0_ left outer join /*scs*/shop_cart_items items1_ on shopcart0_.id=items1_.sc_id where shopcart0_.id=?
12:08:00.346 [main] DEBUG org.hibernate.SQL - select shopcartit0_.sc_id as sc1_1_0_, shopcartit0_.product_id as product2_1_0_, shopcartit0_.quantity as quantity1_0_, shopcartit0_.product_price_code as product4_1_0_, shopcartit0_.service_term_code as service5_1_0_, shopcartit0_.fulfillment_type as fulfillm6_1_0_, shopcartit0_.product_platform_code as product7_1_0_, shopcartit0_.base_calculated_price as base8_1_0_, shopcartit0_.discount_calculated_price as discount9_1_0_, shopcartit0_.partner_code as partner10_1_0_, shopcartit0_.click_path as click11_1_0_, shopcartit0_.offer_page as offer12_1_0_, shopcartit0_.local_source as local13_1_0_, shopcartit0_.referring_source as referring14_1_0_, shopcartit0_.create_time as create15_1_0_, shopcartit0_.modify_time as modify16_1_0_ from /*scs*/shop_cart_items shopcartit0_ where shopcartit0_.sc_id=? and shopcartit0_.product_id=?
12:08:00.394 [main] DEBUG org.hibernate.SQL - select modifiers0_.sc_id as sc2_1_, modifiers0_.modifier_type_code as modifier1_1_, modifiers0_.modifier_type_code as modifier1_2_0_, modifiers0_.sc_id as sc2_2_0_, modifiers0_.modifier_value as modifier3_2_0_, modifiers0_.create_time as create4_2_0_, modifiers0_.modify_time as modify5_2_0_ from /*scs*/shop_cart_modifiers modifiers0_ where modifiers0_.sc_id=?
12:08:00.428 [main] DEBUG org.hibernate.SQL - select modifiers0_.scitm_sc_id as scitm1_1_, modifiers0_.scitm_product_id as scitm2_1_, modifiers0_.modifier_type_code as modifier3_1_, modifiers0_.scitm_sc_id as scitm1_3_0_, modifiers0_.scitm_product_id as scitm2_3_0_, modifiers0_.modifier_type_code as modifier3_3_0_, modifiers0_.modifier_value as modifier4_3_0_, modifiers0_.create_time as create5_3_0_, modifiers0_.modify_time as modify6_3_0_ from /*scs*/shop_cart_item_modifiers modifiers0_ where modifiers0_.scitm_sc_id=? and modifiers0_.scitm_product_id=?
12:08:00.471 [main] DEBUG org.hibernate.SQL - select cartitemmo0_.scitm_sc_id as scitm1_3_0_, cartitemmo0_.scitm_product_id as scitm2_3_0_, cartitemmo0_.modifier_type_code as modifier3_3_0_, cartitemmo0_.modifier_value as modifier4_3_0_, cartitemmo0_.create_time as create5_3_0_, cartitemmo0_.modify_time as modify6_3_0_ from /*scs*/shop_cart_item_modifiers cartitemmo0_ where cartitemmo0_.scitm_sc_id=? and cartitemmo0_.scitm_product_id=? and cartitemmo0_.modifier_type_code=?
12:08:00.510 [main] DEBUG org.hibernate.SQL - select modifiers0_.scitm_sc_id as scitm1_1_, modifiers0_.scitm_product_id as scitm2_1_, modifiers0_.modifier_type_code as modifier3_1_, modifiers0_.scitm_sc_id as scitm1_3_0_, modifiers0_.scitm_product_id as scitm2_3_0_, modifiers0_.modifier_type_code as modifier3_3_0_, modifiers0_.modifier_value as modifier4_3_0_, modifiers0_.create_time as create5_3_0_, modifiers0_.modify_time as modify6_3_0_ from /*scs*/shop_cart_item_modifiers modifiers0_ where modifiers0_.scitm_sc_id=? and modifiers0_.scitm_product_id=?
12:08:00.548 [main] DEBUG org.hibernate.SQL - select cartitemmo0_.scitm_sc_id as scitm1_3_0_, cartitemmo0_.scitm_product_id as scitm2_3_0_, cartitemmo0_.modifier_type_code as modifier3_3_0_, cartitemmo0_.modifier_value as modifier4_3_0_, cartitemmo0_.create_time as create5_3_0_, cartitemmo0_.modify_time as modify6_3_0_ from /*scs*/shop_cart_item_modifiers cartitemmo0_ where cartitemmo0_.scitm_sc_id=? and cartitemmo0_.scitm_product_id=? and cartitemmo0_.modifier_type_code=?

Debug level Hibernate log excerpt:
12:09:40.917 [main] DEBUG org.hibernate.impl.SessionImpl - opened session at timestamp: 11764913809
12:09:40.918 [main] DEBUG com.real.test.scs.dao.HibernateCascadeDeleteTest - QUERY-BEGIN
12:09:40.919 [main] DEBUG org.hibernate.event.def.DefaultLoadEventListener - loading entity: [com.real.scs.domain.shopcart.ShopCart#2019]
12:09:40.919 [main] DEBUG org.hibernate.event.def.DefaultLoadEventListener - attempting to resolve: [com.real.scs.domain.shopcart.ShopCart#2019]
12:09:40.920 [main] DEBUG org.hibernate.event.def.DefaultLoadEventListener - object not resolved in any cache: [com.real.scs.domain.shopcart.ShopCart#2019]
12:09:40.920 [main] DEBUG org.hibernate.persister.entity.AbstractEntityPersister - Fetching entity: [com.real.scs.domain.shopcart.ShopCart#2019]
12:09:40.920 [main] DEBUG org.hibernate.loader.Loader - loading entity: [com.real.scs.domain.shopcart.ShopCart#2019]
12:09:40.924 [main] DEBUG org.hibernate.jdbc.AbstractBatcher - about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
12:09:40.924 [main] DEBUG org.hibernate.jdbc.ConnectionManager - opening JDBC connection
12:09:40.925 [main] DEBUG org.hibernate.SQL - select shopcart0_.id as id0_1_, shopcart0_.version as version0_1_, shopcart0_.guid as guid0_1_, shopcart0_.uds_user_guid as uds4_0_1_, shopcart0_.storefront_scope as storefront5_0_1_, shopcart0_.currency_code as currency6_0_1_, shopcart0_.create_time as create7_0_1_, shopcart0_.modify_time as modify8_0_1_, shopcart0_.partner_code as partner9_0_1_, shopcart0_.click_path as click10_0_1_, shopcart0_.offer_page as offer11_0_1_, shopcart0_.local_source as local12_0_1_, shopcart0_.referring_source as referring13_0_1_, items1_.sc_id as sc1_3_, items1_.product_id as product2_3_, items1_.sc_id as sc1_1_0_, items1_.product_id as product2_1_0_, items1_.quantity as quantity1_0_, items1_.product_price_code as product4_1_0_, items1_.service_term_code as service5_1_0_, items1_.fulfillment_type as fulfillm6_1_0_, items1_.product_platform_code as product7_1_0_, items1_.base_calculated_price as base8_1_0_, items1_.discount_calculated_price as discount9_1_0_, items1_.partner_code as partner10_1_0_, items1_.click_path as click11_1_0_, items1_.offer_page as offer12_1_0_, items1_.local_source as local13_1_0_, items1_.referring_source as referring14_1_0_, items1_.create_time as create15_1_0_, items1_.modify_time as modify16_1_0_ from /*scs*/shop_carts shopcart0_ left outer join /*scs*/shop_cart_items items1_ on shopcart0_.id=items1_.sc_id where shopcart0_.id=?
12:09:40.925 [main] DEBUG org.hibernate.jdbc.AbstractBatcher - preparing statement
12:09:40.925 [main] DEBUG org.hibernate.type.LongType - binding '2019' to parameter: 1
12:09:40.982 [main] DEBUG org.hibernate.jdbc.AbstractBatcher - about to open ResultSet (open ResultSets: 0, globally: 0)
12:09:40.982 [main] DEBUG org.hibernate.loader.Loader - processing result set
12:09:40.982 [main] DEBUG org.hibernate.loader.Loader - result set row: 0
12:09:40.983 [main] DEBUG org.hibernate.type.LongType - returning '2019' as column: sc1_1_0_
12:09:40.983 [main] DEBUG org.hibernate.event.def.DefaultLoadEventListener - loading entity: [com.real.scs.domain.shopcart.ShopCart#2019]
12:09:40.983 [main] DEBUG org.hibernate.event.def.DefaultLoadEventListener - creating new proxy for entity
12:09:40.990 [main] DEBUG org.hibernate.loader.Loader - result row: EntityKey[com.real.scs.domain.shopcart.ShopCartItem#component[shopCart,product]{product=1000, shopCart=com.real.scs.domain.shopcart.ShopCart#2019}], EntityKey[com.real.scs.domain.shopcart.ShopCart#2019]
12:09:40.991 [main] DEBUG org.hibernate.loader.Loader - Initializing object from ResultSet: [com.real.scs.domain.shopcart.ShopCartItem#component[shopCart,product]{product=1000, shopCart=com.real.scs.domain.shopcart.ShopCart#2019}]
12:09:40.993 [main] DEBUG org.hibernate.persister.entity.AbstractEntityPersister - Hydrating entity: [com.real.scs.domain.shopcart.ShopCartItem#component[shopCart,product]{product=1000, shopCart=com.real.scs.domain.shopcart.ShopCart#2019}]
12:09:40.994 [main] DEBUG org.hibernate.type.IntegerType - returning '1' as column: quantity1_0_
12:09:40.994 [main] DEBUG org.hibernate.type.BigDecimalType - returning '1' as column: base8_1_0_
12:09:40.995 [main] DEBUG org.hibernate.type.BigDecimalType - returning '1' as column: discount9_1_0_
12:09:40.995 [main] DEBUG org.hibernate.type.StringType - returning null as column: partner10_1_0_
12:09:40.996 [main] DEBUG org.hibernate.type.StringType - returning null as column: click11_1_0_
12:09:40.997 [main] DEBUG org.hibernate.type.StringType - returning null as column: offer12_1_0_
12:09:40.997 [main] DEBUG org.hibernate.type.StringType - returning null as column: local13_1_0_
12:09:40.997 [main] DEBUG org.hibernate.type.StringType - returning null as column: referring14_1_0_
12:09:40.999 [main] DEBUG org.hibernate.type.CalendarType - returning '2007-04-13 12:09:40' as column: create15_1_0_
12:09:40.999 [main] DEBUG org.hibernate.type.CalendarType - returning null as column: modify16_1_0_
12:09:40.999 [main] DEBUG org.hibernate.loader.Loader - Initializing object from ResultSet: [com.real.scs.domain.shopcart.ShopCart#2019]
12:09:41.000 [main] DEBUG org.hibernate.persister.entity.AbstractEntityPersister - Hydrating entity: [com.real.scs.domain.shopcart.ShopCart#2019]
12:09:41.000 [main] DEBUG org.hibernate.type.CalendarType - returning '2007-04-13 12:09:40' as column: create7_0_1_
12:09:41.001 [main] DEBUG org.hibernate.type.CalendarType - returning null as column: modify8_0_1_
12:09:41.001 [main] DEBUG org.hibernate.type.StringType - returning null as column: partner9_0_1_
12:09:41.001 [main] DEBUG org.hibernate.type.StringType - returning null as column: click10_0_1_
12:09:41.001 [main] DEBUG org.hibernate.type.StringType - returning null as column: offer11_0_1_
12:09:41.001 [main] DEBUG org.hibernate.type.StringType - returning null as column: local12_0_1_
12:09:41.001 [main] DEBUG org.hibernate.type.StringType - returning null as column: referring13_0_1_
12:09:41.002 [main] DEBUG org.hibernate.engine.TwoPhaseLoad - Version: com.real.scs.domain.Version@1
12:09:41.002 [main] DEBUG org.hibernate.type.LongType - returning '2019' as column: sc1_3_
12:09:41.002 [main] DEBUG org.hibernate.loader.Loader - found row of collection: [com.real.scs.domain.shopcart.ShopCart.items#2019]
12:09:41.005 [main] DEBUG org.hibernate.engine.CollectionLoadContext - new collection: instantiating
12:09:41.006 [main] DEBUG org.hibernate.type.LongType - returning '2019' as column: sc1_3_
12:09:41.007 [main] DEBUG org.hibernate.event.def.DefaultLoadEventListener - loading entity: [com.real.scs.domain.shopcart.ShopCart#2019]
12:09:41.007 [main] DEBUG org.hibernate.event.def.DefaultLoadEventListener - entity proxy found in session cache
12:09:41.008 [main] DEBUG org.hibernate.event.def.DefaultLoadEventListener - loading entity: [com.real.scs.domain.shopcart.ShopCartItem#component[shopCart,product]{product=1000, shopCart=com.real.scs.domain.shopcart.ShopCart#2019}]
12:09:41.008 [main] DEBUG org.hibernate.event.def.DefaultLoadEventListener - attempting to resolve: [com.real.scs.domain.shopcart.ShopCartItem#component[shopCart,product]{product=1000, shopCart=com.real.scs.domain.shopcart.ShopCart#2019}]
12:09:41.008 [main] DEBUG org.hibernate.event.def.DefaultLoadEventListener - object not resolved in any cache: [com.real.scs.domain.shopcart.ShopCartItem#component[shopCart,product]{product=1000, shopCart=com.real.scs.domain.shopcart.ShopCart#2019}]
12:09:41.009 [main] DEBUG org.hibernate.persister.entity.AbstractEntityPersister - Fetching entity: [com.real.scs.domain.shopcart.ShopCartItem#component[shopCart,product]{product=1000, shopCart=com.real.scs.domain.shopcart.ShopCart#2019}]
12:09:41.009 [main] DEBUG org.hibernate.loader.Loader - loading entity: [com.real.scs.domain.shopcart.ShopCartItem#component[shopCart,product]{product=1000, shopCart=com.real.scs.domain.shopcart.ShopCart#2019}]
12:09:41.009 [main] DEBUG org.hibernate.jdbc.AbstractBatcher - about to open PreparedStatement (open PreparedStatements: 1, globally: 1)
12:09:41.009 [main] DEBUG org.hibernate.SQL - select shopcartit0_.sc_id as sc1_1_0_, shopcartit0_.product_id as product2_1_0_, shopcartit0_.quantity as quantity1_0_, shopcartit0_.product_price_code as product4_1_0_, shopcartit0_.service_term_code as service5_1_0_, shopcartit0_.fulfillment_type as fulfillm6_1_0_, shopcartit0_.product_platform_code as product7_1_0_, shopcartit0_.base_calculated_price as base8_1_0_, shopcartit0_.discount_calculated_price as discount9_1_0_, shopcartit0_.partner_code as partner10_1_0_, shopcartit0_.click_path as click11_1_0_, shopcartit0_.offer_page as offer12_1_0_, shopcartit0_.local_source as local13_1_0_, shopcartit0_.referring_source as referring14_1_0_, shopcartit0_.create_time as create15_1_0_, shopcartit0_.modify_time as modify16_1_0_ from /*scs*/shop_cart_items shopcartit0_ where shopcartit0_.sc_id=? and shopcartit0_.product_id=?
12:09:41.009 [main] DEBUG org.hibernate.jdbc.AbstractBatcher - preparing statement
12:09:41.010 [main] DEBUG org.hibernate.type.LongType - binding '2019' to parameter: 1
12:09:41.053 [main] DEBUG org.hibernate.jdbc.AbstractBatcher - about to open ResultSet (open ResultSets: 1, globally: 1)
12:09:41.166 [main] DEBUG org.hibernate.loader.Loader - processing result set
12:09:41.166 [main] DEBUG org.hibernate.loader.Loader - result set row: 0
12:09:41.166 [main] DEBUG org.hibernate.loader.Loader - result row: EntityKey[com.real.scs.domain.shopcart.ShopCartItem#component[shopCart,product]{product=1000, shopCart=com.real.scs.domain.shopcart.ShopCart#2019}]
12:09:41.167 [main] DEBUG org.hibernate.loader.Loader - Initializing object from ResultSet: [com.real.scs.domain.shopcart.ShopCartItem#component[shopCart,product]{product=1000, shopCart=com.real.scs.domain.shopcart.ShopCart#2019}]
12:09:41.167 [main] DEBUG org.hibernate.persister.entity.AbstractEntityPersister - Hydrating entity: [com.real.scs.domain.shopcart.ShopCartItem#component[shopCart,product]{product=1000, shopCart=com.real.scs.domain.shopcart.ShopCart#2019}]
12:09:41.167 [main] DEBUG org.hibernate.type.IntegerType - returning '1' as column: quantity1_0_
12:09:41.167 [main] DEBUG org.hibernate.type.BigDecimalType - returning '1' as column: base8_1_0_
12:09:41.167 [main] DEBUG org.hibernate.type.BigDecimalType - returning '1' as column: discount9_1_0_
12:09:41.168 [main] DEBUG org.hibernate.type.StringType - returning null as column: partner10_1_0_
12:09:41.168 [main] DEBUG org.hibernate.type.StringType - returning null as column: click11_1_0_
12:09:41.168 [main] DEBUG org.hibernate.type.StringType - returning null as column: offer12_1_0_
12:09:41.168 [main] DEBUG org.hibernate.type.StringType - returning null as column: local13_1_0_
12:09:41.168 [main] DEBUG org.hibernate.type.StringType - returning null as column: referring14_1_0_
12:09:41.169 [main] DEBUG org.hibernate.type.CalendarType - returning '2007-04-13 12:09:40' as column: create15_1_0_
12:09:41.169 [main] DEBUG org.hibernate.type.CalendarType - returning null as column: modify16_1_0_
12:09:41.169 [main] DEBUG org.hibernate.loader.Loader - done processing result set (1 rows)
12:09:41.169 [main] DEBUG org.hibernate.jdbc.AbstractBatcher - about to close ResultSet (open ResultSets: 2, globally: 2)
12:09:41.169 [main] DEBUG org.hibernate.jdbc.AbstractBatcher - about to close PreparedStatement (open PreparedStatements: 2, globally: 2)
12:09:41.170 [main] DEBUG org.hibernate.jdbc.AbstractBatcher - closing statement
12:09:41.171 [main] DEBUG org.hibernate.loader.Loader - total objects hydrated: 1
12:09:41.172 [main] DEBUG org.hibernate.engine.TwoPhaseLoad - resolving associations for [com.real.scs.domain.shopcart.ShopCartItem#component[shopCart,product]{product=1000, shopCart=com.real.scs.domain.shopcart.ShopCart#2019}]
12:09:41.173 [main] DEBUG org.hibernate.engine.CollectionLoadContext - creating collection wrapper:[com.real.scs.domain.shopcart.ShopCartItem.modifiers#component[shopCart,product]{product=1000, shopCart=com.real.scs.domain.shopcart.ShopCart#2019}]
12:09:41.174 [main] DEBUG org.hibernate.engine.TwoPhaseLoad - done materializing entity [com.real.scs.domain.shopcart.ShopCartItem#component[shopCart,product]{product=1000, shopCart=com.real.scs.domain.shopcart.ShopCart#2019}]
12:09:41.174 [main] DEBUG org.hibernate.loader.Loader - done entity load
12:09:41.175 [main] DEBUG org.hibernate.loader.Loader - done processing result set (1 rows)
12:09:41.175 [main] DEBUG org.hibernate.jdbc.AbstractBatcher - about to close ResultSet (open ResultSets: 1, globally: 1)
12:09:41.175 [main] DEBUG org.hibernate.jdbc.AbstractBatcher - about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
12:09:41.175 [main] DEBUG org.hibernate.jdbc.AbstractBatcher - closing statement
12:09:41.175 [main] DEBUG org.hibernate.loader.Loader - total objects hydrated: 2
12:09:41.175 [main] DEBUG org.hibernate.engine.TwoPhaseLoad - resolving associations for [com.real.scs.domain.shopcart.ShopCartItem#component[shopCart,product]{product=1000, shopCart=com.real.scs.domain.shopcart.ShopCart#2019}]
12:09:41.176 [main] DEBUG org.hibernate.engine.CollectionLoadContext - creating collection wrapper:[com.real.scs.domain.shopcart.ShopCartItem.modifiers#component[shopCart,product]{product=1000, shopCart=com.real.scs.domain.shopcart.ShopCart#2019}]
12:09:41.176 [main] DEBUG org.hibernate.engine.TwoPhaseLoad - done materializing entity [com.real.scs.domain.shopcart.ShopCartItem#component[shopCart,product]{product=1000, shopCart=com.real.scs.domain.shopcart.ShopCart#2019}]
12:09:41.177 [main] DEBUG org.hibernate.engine.TwoPhaseLoad - resolving associations for [com.real.scs.domain.shopcart.ShopCart#2019]
12:09:41.177 [main] DEBUG org.hibernate.engine.CollectionLoadContext - returning loading collection:[com.real.scs.domain.shopcart.ShopCart.items#2019]
12:09:41.177 [main] DEBUG org.hibernate.engine.CollectionLoadContext - creating collection wrapper:[com.real.scs.domain.shopcart.ShopCart.modifiers#2019]
12:09:41.177 [main] DEBUG org.hibernate.engine.TwoPhaseLoad - done materializing entity [com.real.scs.domain.shopcart.ShopCart#2019]
12:09:41.178 [main] DEBUG org.hibernate.engine.CollectionLoadContext - 1 collections were found in result set for role: com.real.scs.domain.shopcart.ShopCart.items
12:09:41.178 [main] DEBUG org.hibernate.engine.CollectionLoadContext - collection fully initialized: [com.real.scs.domain.shopcart.ShopCart.items#2019]
12:09:41.178 [main] DEBUG org.hibernate.engine.CollectionLoadContext - 1 collections initialized for role: com.real.scs.domain.shopcart.ShopCart.items
12:09:41.179 [main] DEBUG org.hibernate.engine.StatefulPersistenceContext - initializing non-lazy collections
12:09:41.180 [main] DEBUG org.hibernate.event.def.DefaultInitializeCollectionEventListener - initializing collection [com.real.scs.domain.shopcart.ShopCart.modifiers#2019]
12:09:41.180 [main] DEBUG org.hibernate.event.def.DefaultInitializeCollectionEventListener - checking second-level cache
12:09:41.180 [main] DEBUG org.hibernate.event.def.DefaultInitializeCollectionEventListener - collection not cached
12:09:41.180 [main] DEBUG org.hibernate.loader.Loader - loading collection: [com.real.scs.domain.shopcart.ShopCart.modifiers#2019]
12:09:41.181 [main] DEBUG org.hibernate.jdbc.AbstractBatcher - about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
12:09:41.181 [main] DEBUG org.hibernate.SQL - select modifiers0_.sc_id as sc2_1_, modifiers0_.modifier_type_code as modifier1_1_, modifiers0_.modifier_type_code as modifier1_2_0_, modifiers0_.sc_id as sc2_2_0_, modifiers0_.modifier_value as modifier3_2_0_, modifiers0_.create_time as create4_2_0_, modifiers0_.modify_time as modify5_2_0_ from /*scs*/shop_cart_modifiers modifiers0_ where modifiers0_.sc_id=?
12:09:41.181 [main] DEBUG org.hibernate.jdbc.AbstractBatcher - preparing statement
12:09:41.181 [main] DEBUG org.hibernate.type.LongType - binding '2019' to parameter: 1
12:09:41.232 [main] DEBUG org.hibernate.jdbc.AbstractBatcher - about to open ResultSet (open ResultSets: 0, globally: 0)
12:09:41.232 [main] DEBUG org.hibernate.loader.Loader - result set contains (possibly empty) collection: [com.real.scs.domain.shopcart.ShopCart.modifiers#2019]
12:09:41.232 [main] DEBUG org.hibernate.engine.CollectionLoadContext - uninitialized collection: initializing
12:09:41.232 [main] DEBUG org.hibernate.loader.Loader - processing result set
12:09:41.233 [main] DEBUG org.hibernate.loader.Loader - done processing result set (0 rows)
12:09:41.233 [main] DEBUG org.hibernate.jdbc.AbstractBatcher - about to close ResultSet (open ResultSets: 1, globally: 1)
12:09:41.233 [main] DEBUG org.hibernate.jdbc.AbstractBatcher - about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
12:09:41.233 [main] DEBUG org.hibernate.jdbc.AbstractBatcher - closing statement
12:09:41.233 [main] DEBUG org.hibernate.loader.Loader - total objects hydrated: 0
12:09:41.233 [main] DEBUG org.hibernate.engine.CollectionLoadContext - 1 collections were found in result set for role: com.real.scs.domain.shopcart.ShopCart.modifiers
12:09:41.234 [main] DEBUG org.hibernate.engine.CollectionLoadContext - collection fully initialized: [com.real.scs.domain.shopcart.ShopCart.modifiers#2019]
12:09:41.234 [main] DEBUG org.hibernate.engine.CollectionLoadContext - 1 collections initialized for role: com.real.scs.domain.shopcart.ShopCart.modifiers
12:09:41.234 [main] DEBUG org.hibernate.loader.Loader - done loading collection
12:09:41.234 [main] DEBUG org.hibernate.event.def.DefaultInitializeCollectionEventListener - collection initialized
12:09:41.234 [main] DEBUG org.hibernate.event.def.DefaultInitializeCollectionEventListener - initializing collection [com.real.scs.domain.shopcart.ShopCartItem.modifiers#component[shopCart,product]{product=1000, shopCart=com.real.scs.domain.shopcart.ShopCart#2019}]
12:09:41.235 [main] DEBUG org.hibernate.event.def.DefaultInitializeCollectionEventListener - checking second-level cache
12:09:41.235 [main] DEBUG org.hibernate.event.def.DefaultInitializeCollectionEventListener - collection not cached
12:09:41.235 [main] DEBUG org.hibernate.loader.Loader - loading collection: [com.real.scs.domain.shopcart.ShopCartItem.modifiers#component[shopCart,product]{product=1000, shopCart=com.real.scs.domain.shopcart.ShopCart#2019}]
12:09:41.235 [main] DEBUG org.hibernate.jdbc.AbstractBatcher - about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
12:09:41.235 [main] DEBUG org.hibernate.SQL - select modifiers0_.scitm_sc_id as scitm1_1_, modifiers0_.scitm_product_id as scitm2_1_, modifiers0_.modifier_type_code as modifier3_1_, modifiers0_.scitm_sc_id as scitm1_3_0_, modifiers0_.scitm_product_id as scitm2_3_0_, modifiers0_.modifier_type_code as modifier3_3_0_, modifiers0_.modifier_value as modifier4_3_0_, modifiers0_.create_time as create5_3_0_, modifiers0_.modify_time as modify6_3_0_ from /*scs*/shop_cart_item_modifiers modifiers0_ where modifiers0_.scitm_sc_id=? and modifiers0_.scitm_product_id=?
12:09:41.235 [main] DEBUG org.hibernate.jdbc.AbstractBatcher - preparing statement
12:09:41.236 [main] DEBUG org.hibernate.type.LongType - binding '2019' to parameter: 1
12:09:41.302 [main] DEBUG org.hibernate.jdbc.AbstractBatcher - about to open ResultSet (open ResultSets: 0, globally: 0)
12:09:41.302 [main] DEBUG org.hibernate.loader.Loader - result set contains (possibly empty) collection: [com.real.scs.domain.shopcart.ShopCartItem.modifiers#component[shopCart,product]{product=1000, shopCart=com.real.scs.domain.shopcart.ShopCart#2019}]
12:09:41.302 [main] DEBUG org.hibernate.engine.CollectionLoadContext - uninitialized collection: initializing
12:09:41.302 [main] DEBUG org.hibernate.loader.Loader - processing result set
12:09:41.302 [main] DEBUG org.hibernate.loader.Loader - result set row: 0
12:09:41.303 [main] DEBUG org.hibernate.type.LongType - returning '2019' as column: scitm1_3_0_
12:09:41.303 [main] DEBUG org.hibernate.event.def.DefaultLoadEventListener - loading entity: [com.real.scs.domain.shopcart.ShopCart#2019]
12:09:41.303 [main] DEBUG org.hibernate.event.def.DefaultLoadEventListener - entity proxy found in session cache
12:09:41.303 [main] DEBUG org.hibernate.type.StringType - returning 'testSaveCartItemModifier' as column: modifier3_3_0_
12:09:41.304 [main] DEBUG org.hibernate.event.def.DefaultLoadEventListener - loading entity: [com.real.scs.domain.shopcart.ShopCartItem#component[shopCart,product]{product=1000, shopCart=com.real.scs.domain.shopcart.ShopCart#2019}]
12:09:41.304 [main] DEBUG org.hibernate.event.def.DefaultLoadEventListener - creating new proxy for entity
12:09:41.310 [main] DEBUG org.hibernate.loader.Loader - result row: EntityKey[com.real.scs.domain.shopcart.CartItemModifier#component[shopCartItem,modifierTypeCode]{shopCartItem=com.real.scs.domain.shopcart.ShopCartItem, modifierTypeCode=testSaveCartItemModifier}]
12:09:41.310 [main] DEBUG org.hibernate.loader.Loader - Initializing object from ResultSet: [com.real.scs.domain.shopcart.CartItemModifier#component[shopCartItem,modifierTypeCode]{shopCartItem=com.real.scs.domain.shopcart.ShopCartItem, modifierTypeCode=testSaveCartItemModifier}]
12:09:41.310 [main] DEBUG org.hibernate.persister.entity.AbstractEntityPersister - Hydrating entity: [com.real.scs.domain.shopcart.CartItemModifier#component[shopCartItem,modifierTypeCode]{shopCartItem=com.real.scs.domain.shopcart.ShopCartItem, modifierTypeCode=testSaveCartItemModifier}]
12:09:41.310 [main] DEBUG org.hibernate.type.StringType - returning 'modifier value' as column: modifier4_3_0_
12:09:41.311 [main] DEBUG org.hibernate.type.CalendarType - returning '2007-04-13 12:09:40' as column: create5_3_0_
12:09:41.311 [main] DEBUG org.hibernate.type.CalendarType - returning null as column: modify6_3_0_
12:09:41.311 [main] DEBUG org.hibernate.type.LongType - returning '2019' as column: scitm1_1_
12:09:41.312 [main] DEBUG org.hibernate.event.def.DefaultLoadEventListener - loading entity: [com.real.scs.domain.shopcart.ShopCart#2019]
12:09:41.312 [main] DEBUG org.hibernate.event.def.DefaultLoadEventListener - entity proxy found in session cache
12:09:41.312 [main] DEBUG org.hibernate.loader.Loader - found row of collection: [com.real.scs.domain.shopcart.ShopCartItem.modifiers#component[shopCart,product]{product=1000, shopCart=com.real.scs.domain.shopcart.ShopCart#2019}]
12:09:41.313 [main] DEBUG org.hibernate.engine.CollectionLoadContext - new collection: instantiating
12:09:41.313 [main] DEBUG org.hibernate.type.LongType - returning '2019' as column: scitm1_1_
12:09:41.313 [main] DEBUG org.hibernate.event.def.DefaultLoadEventListener - loading entity: [com.real.scs.domain.shopcart.ShopCart#2019]
12:09:41.313 [main] DEBUG org.hibernate.event.def.DefaultLoadEventListener - entity proxy found in session cache
12:09:41.314 [main] DEBUG org.hibernate.type.StringType - returning 'testSaveCartItemModifier' as column: modifier3_1_
12:09:41.314 [main] DEBUG org.hibernate.event.def.DefaultLoadEventListener - loading entity: [com.real.scs.domain.shopcart.ShopCartItem#component[shopCart,product]{product=1000, shopCart=com.real.scs.domain.shopcart.ShopCart#2019}]
12:09:41.314 [main] DEBUG org.hibernate.event.def.DefaultLoadEventListener - creating new proxy for entity
12:09:41.316 [main] DEBUG org.hibernate.event.def.DefaultLoadEventListener - loading entity: [com.real.scs.domain.shopcart.CartItemModifier#component[shopCartItem,modifierTypeCode]{shopCartItem=com.real.scs.domain.shopcart.ShopCartItem, modifierTypeCode=testSaveCartItemModifier}]
12:09:41.316 [main] DEBUG org.hibernate.event.def.DefaultLoadEventListener - attempting to resolve: [com.real.scs.domain.shopcart.CartItemModifier#component[shopCartItem,modifierTypeCode]{shopCartItem=com.real.scs.domain.shopcart.ShopCartItem, modifierTypeCode=testSaveCartItemModifier}]
12:09:41.318 [main] DEBUG org.hibernate.event.def.DefaultLoadEventListener - object not resolved in any cache: [com.real.scs.domain.shopcart.CartItemModifier#component[shopCartItem,modifierTypeCode]{shopCartItem=com.real.scs.domain.shopcart.ShopCartItem, modifierTypeCode=testSaveCartItemModifier}]
12:09:41.319 [main] DEBUG org.hibernate.persister.entity.AbstractEntityPersister - Fetching entity: [com.real.scs.domain.shopcart.CartItemModifier#component[shopCartItem,modifierTypeCode]{shopCartItem=com.real.scs.domain.shopcart.ShopCartItem, modifierTypeCode=testSaveCartItemModifier}]
12:09:41.319 [main] DEBUG org.hibernate.loader.Loader - loading entity: [com.real.scs.domain.shopcart.CartItemModifier#component[shopCartItem,modifierTypeCode]{shopCartItem=com.real.scs.domain.shopcart.ShopCartItem, modifierTypeCode=testSaveCartItemModifier}]
12:09:41.320 [main] DEBUG org.hibernate.jdbc.AbstractBatcher - about to open PreparedStatement (open PreparedStatements: 1, globally: 1)
12:09:41.320 [main] DEBUG org.hibernate.SQL - select cartitemmo0_.scitm_sc_id as scitm1_3_0_, cartitemmo0_.scitm_product_id as scitm2_3_0_, cartitemmo0_.modifier_type_code as modifier3_3_0_, cartitemmo0_.modifier_value as modifier4_3_0_, cartitemmo0_.create_time as create5_3_0_, cartitemmo0_.modify_time as modify6_3_0_ from /*scs*/shop_cart_item_modifiers cartitemmo0_ where cartitemmo0_.scitm_sc_id=? and cartitemmo0_.scitm_product_id=? and cartitemmo0_.modifier_type_code=?
12:09:41.321 [main] DEBUG org.hibernate.jdbc.AbstractBatcher - preparing statement
12:09:41.321 [main] DEBUG org.hibernate.type.LongType - binding '2019' to parameter: 1
12:09:41.321 [main] DEBUG org.hibernate.type.StringType - binding 'testSaveCartItemModifier' to parameter: 3
12:09:41.371 [main] DEBUG org.hibernate.jdbc.AbstractBatcher - about to open ResultSet (open ResultSets: 1, globally: 1)
12:09:41.371 [main] DEBUG org.hibernate.loader.Loader - processing result set
12:09:41.371 [main] DEBUG org.hibernate.loader.Loader - result set row: 0
12:09:41.374 [main] DEBUG org.hibernate.loader.Loader - result row: EntityKey[com.real.scs.domain.shopcart.CartItemModifier#component[shopCartItem,modifierTypeCode]{shopCartItem=com.real.scs.domain.shopcart.ShopCartItem, modifierTypeCode=testSaveCartItemModifier}]
12:09:41.374 [main] DEBUG org.hibernate.loader.Loader - Initializing object from ResultSet: [com.real.scs.domain.shopcart.CartItemModifier#component[shopCartItem,modifierTypeCode]{shopCartItem=com.real.scs.domain.shopcart.ShopCartItem, modifierTypeCode=testSaveCartItemModifier}]
12:09:41.374 [main] DEBUG org.hibernate.persister.entity.AbstractEntityPersister - Hydrating entity: [com.real.scs.domain.shopcart.CartItemModifier#component[shopCartItem,modifierTypeCode]{shopCartItem=com.real.scs.domain.shopcart.ShopCartItem, modifierTypeCode=testSaveCartItemModifier}]
12:09:41.375 [main] DEBUG org.hibernate.type.StringType - returning 'modifier value' as column: modifier4_3_0_
12:09:41.375 [main] DEBUG org.hibernate.type.CalendarType - returning '2007-04-13 12:09:40' as column: create5_3_0_
12:09:41.376 [main] DEBUG org.hibernate.type.CalendarType - returning null as column: modify6_3_0_
12:09:41.376 [main] DEBUG org.hibernate.loader.Loader - done processing result set (1 rows)
12:09:41.376 [main] DEBUG org.hibernate.jdbc.AbstractBatcher - about to close ResultSet (open ResultSets: 2, globally: 2)
12:09:41.376 [main] DEBUG org.hibernate.jdbc.AbstractBatcher - about to close PreparedStatement (open PreparedStatements: 2, globally: 2)
12:09:41.376 [main] DEBUG org.hibernate.jdbc.AbstractBatcher - closing statement
12:09:41.376 [main] DEBUG org.hibernate.loader.Loader - total objects hydrated: 1
12:09:41.377 [main] DEBUG org.hibernate.engine.TwoPhaseLoad - resolving associations for [com.real.scs.domain.shopcart.CartItemModifier#component[shopCartItem,modifierTypeCode]{shopCartItem=com.real.scs.domain.shopcart.ShopCartItem, modifierTypeCode=testSaveCartItemModifier}]
12:09:41.377 [main] DEBUG org.hibernate.engine.TwoPhaseLoad - done materializing entity [com.real.scs.domain.shopcart.CartItemModifier#component[shopCartItem,modifierTypeCode]{shopCartItem=com.real.scs.domain.shopcart.ShopCartItem, modifierTypeCode=testSaveCartItemModifier}]
12:09:41.377 [main] DEBUG org.hibernate.loader.Loader - done entity load
12:09:41.377 [main] DEBUG org.hibernate.loader.Loader - done processing result set (1 rows)
12:09:41.377 [main] DEBUG org.hibernate.jdbc.AbstractBatcher - about to close ResultSet (open ResultSets: 1, globally: 1)
12:09:41.377 [main] DEBUG org.hibernate.jdbc.AbstractBatcher - about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
12:09:41.378 [main] DEBUG org.hibernate.jdbc.AbstractBatcher - closing statement
12:09:41.378 [main] DEBUG org.hibernate.loader.Loader - total objects hydrated: 1
12:09:41.378 [main] DEBUG org.hibernate.engine.TwoPhaseLoad - resolving associations for [com.real.scs.domain.shopcart.CartItemModifier#component[shopCartItem,modifierTypeCode]{shopCartItem=com.real.scs.domain.shopcart.ShopCartItem, modifierTypeCode=testSaveCartItemModifier}]
12:09:41.378 [main] DEBUG org.hibernate.engine.TwoPhaseLoad - done materializing entity [com.real.scs.domain.shopcart.CartItemModifier#component[shopCartItem,modifierTypeCode]{shopCartItem=com.real.scs.domain.shopcart.ShopCartItem, modifierTypeCode=testSaveCartItemModifier}]
12:09:41.379 [main] DEBUG org.hibernate.engine.CollectionLoadContext - 2 collections were found in result set for role: com.real.scs.domain.shopcart.ShopCartItem.modifiers
12:09:41.379 [main] DEBUG org.hibernate.engine.CollectionLoadContext - collection fully initialized: [com.real.scs.domain.shopcart.ShopCartItem.modifiers#component[shopCart,product]{product=1000, shopCart=com.real.scs.domain.shopcart.ShopCart#2019}]
12:09:41.379 [main] DEBUG org.hibernate.engine.CollectionLoadContext - collection fully initialized: [com.real.scs.domain.shopcart.ShopCartItem.modifiers#component[shopCart,product]{product=1000, shopCart=com.real.scs.domain.shopcart.ShopCart#2019}]
12:09:41.379 [main] DEBUG org.hibernate.engine.CollectionLoadContext - 2 collections initialized for role: com.real.scs.domain.shopcart.ShopCartItem.modifiers
12:09:41.380 [main] DEBUG org.hibernate.loader.Loader - done loading collection
12:09:41.380 [main] DEBUG org.hibernate.event.def.DefaultInitializeCollectionEventListener - collection initialized
12:09:41.380 [main] DEBUG org.hibernate.event.def.DefaultInitializeCollectionEventListener - initializing collection [com.real.scs.domain.shopcart.ShopCartItem.modifiers#component[shopCart,product]{product=1000, shopCart=com.real.scs.domain.shopcart.ShopCart#2019}]
12:09:41.380 [main] DEBUG org.hibernate.event.def.DefaultInitializeCollectionEventListener - checking second-level cache
12:09:41.380 [main] DEBUG org.hibernate.event.def.DefaultInitializeCollectionEventListener - collection not cached
12:09:41.380 [main] DEBUG org.hibernate.loader.Loader - loading collection: [com.real.scs.domain.shopcart.ShopCartItem.modifiers#component[shopCart,product]{product=1000, shopCart=com.real.scs.domain.shopcart.ShopCart#2019}]
12:09:41.381 [main] DEBUG org.hibernate.jdbc.AbstractBatcher - about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
12:09:41.381 [main] DEBUG org.hibernate.SQL - select modifiers0_.scitm_sc_id as scitm1_1_, modifiers0_.scitm_product_id as scitm2_1_, modifiers0_.modifier_type_code as modifier3_1_, modifiers0_.scitm_sc_id as scitm1_3_0_, modifiers0_.scitm_product_id as scitm2_3_0_, modifiers0_.modifier_type_code as modifier3_3_0_, modifiers0_.modifier_value as modifier4_3_0_, modifiers0_.create_time as create5_3_0_, modifiers0_.modify_time as modify6_3_0_ from /*scs*/shop_cart_item_modifiers modifiers0_ where modifiers0_.scitm_sc_id=? and modifiers0_.scitm_product_id=?
12:09:41.381 [main] DEBUG org.hibernate.jdbc.AbstractBatcher - preparing statement
12:09:41.381 [main] DEBUG org.hibernate.type.LongType - binding '2019' to parameter: 1
12:09:41.434 [main] DEBUG org.hibernate.jdbc.AbstractBatcher - about to open ResultSet (open ResultSets: 0, globally: 0)
12:09:41.435 [main] DEBUG org.hibernate.loader.Loader - result set contains (possibly empty) collection: [com.real.scs.domain.shopcart.ShopCartItem.modifiers#component[shopCart,product]{product=1000, shopCart=com.real.scs.domain.shopcart.ShopCart#2019}]
12:09:41.435 [main] DEBUG org.hibernate.engine.CollectionLoadContext - uninitialized collection: initializing
12:09:41.435 [main] DEBUG org.hibernate.loader.Loader - processing result set
12:09:41.435 [main] DEBUG org.hibernate.loader.Loader - result set row: 0
12:09:41.435 [main] DEBUG org.hibernate.type.LongType - returning '2019' as column: scitm1_3_0_
12:09:41.436 [main] DEBUG org.hibernate.event.def.DefaultLoadEventListener - loading entity: [com.real.scs.domain.shopcart.ShopCart#2019]
12:09:41.436 [main] DEBUG org.hibernate.event.def.DefaultLoadEventListener - entity proxy found in session cache
12:09:41.436 [main] DEBUG org.hibernate.type.StringType - returning 'testSaveCartItemModifier' as column: modifier3_3_0_
12:09:41.437 [main] DEBUG org.hibernate.event.def.DefaultLoadEventListener - loading entity: [com.real.scs.domain.shopcart.ShopCartItem#component[shopCart,product]{product=1000, shopCart=com.real.scs.domain.shopcart.ShopCart#2019}]
12:09:41.437 [main] DEBUG org.hibernate.event.def.DefaultLoadEventListener - creating new proxy for entity
12:09:41.437 [main] DEBUG org.hibernate.loader.Loader - result row: EntityKey[com.real.scs.domain.shopcart.CartItemModifier#component[shopCartItem,modifierTypeCode]{shopCartItem=com.real.scs.domain.shopcart.ShopCartItem, modifierTypeCode=testSaveCartItemModifier}]
12:09:41.438 [main] DEBUG org.hibernate.loader.Loader - Initializing object from ResultSet: [com.real.scs.domain.shopcart.CartItemModifier#component[shopCartItem,modifierTypeCode]{shopCartItem=com.real.scs.domain.shopcart.ShopCartItem, modifierTypeCode=testSaveCartItemModifier}]
12:09:41.438 [main] DEBUG org.hibernate.persister.entity.AbstractEntityPersister - Hydrating entity: [com.real.scs.domain.shopcart.CartItemModifier#component[shopCartItem,modifierTypeCode]{shopCartItem=com.real.scs.domain.shopcart.ShopCartItem, modifierTypeCode=testSaveCartItemModifier}]
12:09:41.439 [main] DEBUG org.hibernate.type.StringType - returning 'modifier value' as column: modifier4_3_0_
12:09:41.439 [main] DEBUG org.hibernate.type.CalendarType - returning '2007-04-13 12:09:40' as column: create5_3_0_
12:09:41.439 [main] DEBUG org.hibernate.type.CalendarType - returning null as column: modify6_3_0_
12:09:41.440 [main] DEBUG org.hibernate.type.LongType - returning '2019' as column: scitm1_1_
12:09:41.440 [main] DEBUG org.hibernate.event.def.DefaultLoadEventListener - loading entity: [com.real.scs.domain.shopcart.ShopCart#2019]
12:09:41.440 [main] DEBUG org.hibernate.event.def.DefaultLoadEventListener - entity proxy found in session cache
12:09:41.441 [main] DEBUG org.hibernate.loader.Loader - found row of collection: [com.real.scs.domain.shopcart.ShopCartItem.modifiers#component[shopCart,product]{product=1000, shopCart=com.real.scs.domain.shopcart.ShopCart#2019}]
12:09:41.442 [main] DEBUG org.hibernate.engine.CollectionLoadContext - new collection: instantiating
12:09:41.442 [main] DEBUG org.hibernate.type.LongType - returning '2019' as column: scitm1_1_
12:09:41.442 [main] DEBUG org.hibernate.event.def.DefaultLoadEventListener - loading entity: [com.real.scs.domain.shopcart.ShopCart#2019]
12:09:41.443 [main] DEBUG org.hibernate.event.def.DefaultLoadEventListener - entity proxy found in session cache
12:09:41.443 [main] DEBUG org.hibernate.type.StringType - returning 'testSaveCartItemModifier' as column: modifier3_1_
12:09:41.443 [main] DEBUG org.hibernate.event.def.DefaultLoadEventListener - loading entity: [com.real.scs.domain.shopcart.ShopCartItem#component[shopCart,product]{product=1000, shopCart=com.real.scs.domain.shopcart.ShopCart#2019}]
12:09:41.444 [main] DEBUG org.hibernate.event.def.DefaultLoadEventListener - creating new proxy for entity
12:09:41.444 [main] DEBUG org.hibernate.event.def.DefaultLoadEventListener - loading entity: [com.real.scs.domain.shopcart.CartItemModifier#component[shopCartItem,modifierTypeCode]{shopCartItem=com.real.scs.domain.shopcart.ShopCartItem, modifierTypeCode=testSaveCartItemModifier}]
12:09:41.445 [main] DEBUG org.hibernate.event.def.DefaultLoadEventListener - attempting to resolve: [com.real.scs.domain.shopcart.CartItemModifier#component[shopCartItem,modifierTypeCode]{shopCartItem=com.real.scs.domain.shopcart.ShopCartItem, modifierTypeCode=testSaveCartItemModifier}]
12:09:41.445 [main] DEBUG org.hibernate.event.def.DefaultLoadEventListener - object not resolved in any cache: [com.real.scs.domain.shopcart.CartItemModifier#component[shopCartItem,modifierTypeCode]{shopCartItem=com.real.scs.domain.shopcart.ShopCartItem, modifierTypeCode=testSaveCartItemModifier}]
12:09:41.445 [main] DEBUG org.hibernate.persister.entity.AbstractEntityPersister - Fetching entity: [com.real.scs.domain.shopcart.CartItemModifier#component[shopCartItem,modifierTypeCode]{shopCartItem=com.real.scs.domain.shopcart.ShopCartItem, modifierTypeCode=testSaveCartItemModifier}]
12:09:41.445 [main] DEBUG org.hibernate.loader.Loader - loading entity: [com.real.scs.domain.shopcart.CartItemModifier#component[shopCartItem,modifierTypeCode]{shopCartItem=com.real.scs.domain.shopcart.ShopCartItem, modifierTypeCode=testSaveCartItemModifier}]
12:09:41.445 [main] DEBUG org.hibernate.jdbc.AbstractBatcher - about to open PreparedStatement (open PreparedStatements: 1, globally: 1)
12:09:41.446 [main] DEBUG org.hibernate.SQL - select cartitemmo0_.scitm_sc_id as scitm1_3_0_, cartitemmo0_.scitm_product_id as scitm2_3_0_, cartitemmo0_.modifier_type_code as modifier3_3_0_, cartitemmo0_.modifier_value as modifier4_3_0_, cartitemmo0_.create_time as create5_3_0_, cartitemmo0_.modify_time as modify6_3_0_ from /*scs*/shop_cart_item_modifiers cartitemmo0_ where cartitemmo0_.scitm_sc_id=? and cartitemmo0_.scitm_product_id=? and cartitemmo0_.modifier_type_code=?
12:09:41.446 [main] DEBUG org.hibernate.jdbc.AbstractBatcher - preparing statement
12:09:41.446 [main] DEBUG org.hibernate.type.LongType - binding '2019' to parameter: 1
12:09:41.446 [main] DEBUG org.hibernate.type.StringType - binding 'testSaveCartItemModifier' to parameter: 3
12:09:41.508 [main] DEBUG org.hibernate.jdbc.AbstractBatcher - about to open ResultSet (open ResultSets: 1, globally: 1)
12:09:41.509 [main] DEBUG org.hibernate.loader.Loader - processing result set
12:09:41.509 [main] DEBUG org.hibernate.loader.Loader - result set row: 0
12:09:41.509 [main] DEBUG org.hibernate.loader.Loader - result row: EntityKey[com.real.scs.domain.shopcart.CartItemModifier#component[shopCartItem,modifierTypeCode]{shopCartItem=com.real.scs.domain.shopcart.ShopCartItem, modifierTypeCode=testSaveCartItemModifier}]
12:09:41.510 [main] DEBUG org.hibernate.loader.Loader - Initializing object from ResultSet: [com.real.scs.domain.shopcart.CartItemModifier#component[shopCartItem,modifierTypeCode]{shopCartItem=com.real.scs.domain.shopcart.ShopCartItem, modifierTypeCode=testSaveCartItemModifier}]
12:09:41.510 [main] DEBUG org.hibernate.persister.entity.AbstractEntityPersister - Hydrating entity: [com.real.scs.domain.shopcart.CartItemModifier#component[shopCartItem,modifierTypeCode]{shopCartItem=com.real.scs.domain.shopcart.ShopCartItem, modifierTypeCode=testSaveCartItemModifier}]
12:09:41.510 [main] DEBUG org.hibernate.type.StringType - returning 'modifier value' as column: modifier4_3_0_
12:09:41.511 [main] DEBUG org.hibernate.type.CalendarType - returning '2007-04-13 12:09:40' as column: create5_3_0_
12:09:41.512 [main] DEBUG org.hibernate.type.CalendarType - returning null as column: modify6_3_0_
12:09:41.512 [main] DEBUG org.hibernate.loader.Loader - done processing result set (1 rows)
12:09:41.512 [main] DEBUG org.hibernate.jdbc.AbstractBatcher - about to close ResultSet (open ResultSets: 2, globally: 2)
12:09:41.512 [main] DEBUG org.hibernate.jdbc.AbstractBatcher - about to close PreparedStatement (open PreparedStatements: 2, globally: 2)
12:09:41.512 [main] DEBUG org.hibernate.jdbc.AbstractBatcher - closing statement
12:09:41.512 [main] DEBUG org.hibernate.loader.Loader - total objects hydrated: 1
12:09:41.513 [main] DEBUG org.hibernate.engine.TwoPhaseLoad - resolving associations for [com.real.scs.domain.shopcart.CartItemModifier#component[shopCartItem,modifierTypeCode]{shopCartItem=com.real.scs.domain.shopcart.ShopCartItem, modifierTypeCode=testSaveCartItemModifier}]
12:09:41.513 [main] DEBUG org.hibernate.engine.TwoPhaseLoad - done materializing entity [com.real.scs.domain.shopcart.CartItemModifier#component[shopCartItem,modifierTypeCode]{shopCartItem=com.real.scs.domain.shopcart.ShopCartItem, modifierTypeCode=testSaveCartItemModifier}]
12:09:41.513 [main] DEBUG org.hibernate.loader.Loader - done entity load
12:09:41.513 [main] DEBUG org.hibernate.loader.Loader - done processing result set (1 rows)
12:09:41.513 [main] DEBUG org.hibernate.jdbc.AbstractBatcher - about to close ResultSet (open ResultSets: 1, globally: 1)
12:09:41.514 [main] DEBUG org.hibernate.jdbc.AbstractBatcher - about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
12:09:41.514 [main] DEBUG org.hibernate.jdbc.AbstractBatcher - closing statement
12:09:41.514 [main] DEBUG org.hibernate.loader.Loader - total objects hydrated: 1
12:09:41.514 [main] DEBUG org.hibernate.engine.TwoPhaseLoad - resolving associations for [com.real.scs.domain.shopcart.CartItemModifier#component[shopCartItem,modifierTypeCode]{shopCartItem=com.real.scs.domain.shopcart.ShopCartItem, modifierTypeCode=testSaveCartItemModifier}]
12:09:41.514 [main] DEBUG org.hibernate.engine.TwoPhaseLoad - done materializing entity [com.real.scs.domain.shopcart.CartItemModifier#component[shopCartItem,modifierTypeCode]{shopCartItem=com.real.scs.domain.shopcart.ShopCartItem, modifierTypeCode=testSaveCartItemModifier}]
12:09:41.515 [main] DEBUG org.hibernate.engine.CollectionLoadContext - 2 collections were found in result set for role: com.real.scs.domain.shopcart.ShopCartItem.modifiers
12:09:41.515 [main] DEBUG org.hibernate.engine.CollectionLoadContext - collection fully initialized: [com.real.scs.domain.shopcart.ShopCartItem.modifiers#component[shopCart,product]{product=1000, shopCart=com.real.scs.domain.shopcart.ShopCart#2019}]
12:09:41.515 [main] DEBUG org.hibernate.engine.CollectionLoadContext - collection fully initialized: [com.real.scs.domain.shopcart.ShopCartItem.modifiers#component[shopCart,product]{product=1000, shopCart=com.real.scs.domain.shopcart.ShopCart#2019}]
12:09:41.516 [main] DEBUG org.hibernate.engine.CollectionLoadContext - 2 collections initialized for role: com.real.scs.domain.shopcart.ShopCartItem.modifiers
12:09:41.516 [main] DEBUG org.hibernate.loader.Loader - done loading collection
12:09:41.516 [main] DEBUG org.hibernate.event.def.DefaultInitializeCollectionEventListener - collection initialized
12:09:41.516 [main] DEBUG org.hibernate.loader.Loader - done entity load
12:09:41.516 [main] DEBUG org.hibernate.jdbc.JDBCContext - after autocommit
12:09:41.516 [main] DEBUG org.hibernate.jdbc.ConnectionManager - transaction completed on session with on_close connection release mode; be sure to close the session to release JDBC resources!
12:09:41.516 [main] DEBUG org.hibernate.impl.SessionImpl - after transaction completion
12:09:41.517 [main] DEBUG org.hibernate.impl.SessionImpl - closing session
12:09:41.517 [main] DEBUG org.hibernate.jdbc.ConnectionManager - performing cleanup
12:09:41.517 [main] DEBUG org.hibernate.jdbc.ConnectionManager - releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
12:09:41.518 [main] DEBUG org.hibernate.jdbc.JDBCContext - after transaction completion
12:09:41.518 [main] DEBUG org.hibernate.jdbc.ConnectionManager - transaction completed on session with on_close connection release mode; be sure to close the session to release JDBC resources!
12:09:41.518 [main] DEBUG org.hibernate.impl.SessionImpl - after transaction completion

Problems with Session and transaction handling?

Read this: http://hibernate.org/42.html
Top
 Profile  
 
ziodraw
 Post subject:
PostPosted: Thu Sep 13, 2007 6:08 am 
Newbie

Joined: Thu Sep 13, 2007 4:55 am
Posts: 4
This is the same thing i've done. But I have one problem. I don't get all records on the last section. I get everytime only one record. but in the first section where one id references to a table with two keys (composite-id) there I get all associated records and I've no idea why. Mysterios.
Top
 Profile  
 
Display posts from previous:  Sort by  
Forum locked This topic is locked, you cannot edit posts or make further replies.  Page 1 of 1
  [ 2 posts ] 

Board index » Hibernate & Java Persistence » Hibernate Users

All times are UTC - 5 hours [ DST ]

You cannot post new topics in this forum
You cannot reply to topics in this forum
You cannot edit your posts in this forum
You cannot delete your posts in this forum

Search for:
© Copyright 2014, Red Hat Inc. All rights reserved. JBoss and Hibernate are registered trademarks and servicemarks of Red Hat, Inc.