Hibernate Community • View topic - no update issued for changed property

View unanswered posts | View active topics

Board index » Hibernate & Java Persistence » Hibernate Users

All times are UTC - 5 hours [ DST ]

no update issued for changed property

Page 1 of 1

[ 6 posts ]

Previous topic | Next topic

Author

Message

ertnutler

Post subject: no update issued for changed property

Posted: Fri Jan 06, 2006 6:02 pm

Newbie

Joined: Wed Mar 23, 2005 9:33 am
Posts: 11

I'm sure I'm doing something stupid, but I can't for the life of me figure out what it is. All I want to do is update the availableQuantity property on the Purchaseable persistent class. I load a Product subclass of it, update the property, then commit the transaction, but Hibernate issues no SQL update even though the code is executing within a transaction and the property is dirty. Even the Printer prints out the updated value:

16:43:27,790 DEBUG Printer:90 - com.xxx.commerce.model.Product{fileAssets=<uninitialized>, width=24.0, manufacturer=com.xxx.commerce.model.Manufacturer#4, lastUpdateBy=admin, categories=<uninitialized>, thumbnailName=1135824976532.jpg, id=1, height=12.0, backorderMaxQuantity=5, name=Test Product, orderedQuantity=5, productCode=1234, active=true, group=false, bargainPrice=1299.0, depth=35.0, notes=These are some arbitary internal notes that can be sent., createdBy=admin, availableQuantity=3, retailPrice=1599.99, version=4, individuallyPurchaseable=true, groups=<uninitialized>, description=Test Product Description., lastUpdate=2005-12-30 00:01:50, createdOn=2005-12-28 21:56:02, weight=125.0}

Somebody please tell me I'm doing something stupid. My test case:

Code:

public void testSimple() throws Exception {
   Transaction tx = session.beginTransaction();
   Purchaseable p = (Purchaseable)session.load(Purchaseable.class, new Long(1));
   p.decrementAvailableCount(new Integer(2));
   tx.commit();
}

Where decrementAvailableQuantity() looks like this:

Code:

public void decrementAvailableCount(Integer ordered) {
   if(ordered.intValue() > getOrderableQuantity().intValue())
      throw new InsufficientInventoryAvailableException("Requested quantity exceeds orderable quantity for Purchaseable [" + getId() + "]");

   logger.info("Decrementing available quantity for Purchaseable#" + getId() + " by " + ordered.intValue());
   setAvailableQuantity(new Integer(getAvailableQuantity().intValue() - ordered.intValue()));
}

And setAvailableQuantity(Integer ordered) looks like this:

Code:

public void setAvailableQuantity(Integer ordered) {
      logger.info("Setting available quantity for Purchaseable#" + getId() + " to " + ordered);
      this.availableQuantity = ordered;
   }

Hibernate version: 3.0.3

Mapping documents:

Code:

=======================================
Purchaseable.hbm.xml
=======================================

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

<hibernate-mapping package="com.xxx.commerce.model">

   <class name="Purchaseable" table="purchaseable" lazy="false">
      <id
         name="id"
         type="long"
         column="purchaseable_id"
         access="field"
         >
         <generator class="native"/>
      </id>

      <discriminator column="group_flag"/>
      <version name="version" column="version" access="field"/>

      <property
         name="group"
         type="yes_no"
         column="group_flag"
         not-null="true"
         length="1"
         insert="false"
         update="false"
         />
      <property
         name="name"
         type="java.lang.String"
         column="name"
         not-null="true"
         />
      <property
         name="description"
         type="text"
         column="description"
         />
      <property
         name="notes"
         type="text"
         column="notes"
         />
      <property
         name="active"
         type="yes_no"
         column="active_flag"
         />
      <property
         name="individuallyPurchaseable"
         type="yes_no"
         column="individually_purchaseable_flag"
         />
      <property
         name="thumbnailName"
         type="java.lang.String"
         column="thumbnail"
         />
      <property
         name="productCode"
         type="java.lang.String"
         column="code"
         />
      <property
         name="weight"
         type="com.xxx.commerce.persistence.customtype.CommerceDoubleTypeCustom"
         column="weight"
         />
      <property
         name="bargainPrice"
         type="com.xxx.commerce.persistence.customtype.CommerceDoubleTypeCustom"
         column="bargain_price"
         not-null="true"
         />
      <property
         name="retailPrice"
         type="com.xxx.commerce.persistence.customtype.CommerceDoubleTypeCustom"
         column="retail_price"
         />
      <property
         name="orderedQuantity"
         type="int"
         column="ordered_qty"
         not-null="true"
         />
      <property
         name="availableQuantity"
         type="int"
         column="available_qty"
         not-null="true"
         />
      <property
         name="backorderMaxQuantity"
         type="int"
         column="backorder_max_qty"
         />
      <property
         name="createdBy"
         type="java.lang.String"
         column="created_by"
         not-null="true"
         />
      <property
         name="createdOn"
         type="java.sql.Timestamp"
         column="created_on"
         not-null="true"
         />
      <property
         name="lastUpdate"
         type="java.sql.Timestamp"
         column="last_update"
         />
      <property
         name="lastUpdateBy"
         type="java.lang.String"
         column="last_update_by"
         />

      <!-- Associations -->

      <set name="fileAssets"
         table="purchaseable_asset"
         lazy="true"
         inverse="false"
         cascade="save-update"
         >
         <key column="purchaseable_id"/>
         <many-to-many class="FileAsset" column="file_asset_id"/>
      </set>

      <many-to-one
         name="manufacturer"
         class="Manufacturer"
         not-null="true"
         >
         <column name="manufacturer_id"/>
      </many-to-one>

      <set name="categories"
         lazy="true"
         cascade="save-update"
         table="purchaseable_category_entry"
         inverse="false"
         >
         <key column="purchaseable_id"/>
         <many-to-many class="PurchaseableCategory" column="purchaseable_category_id"/>
      </set>
   </class>
</hibernate-mapping>

=======================================
Product.hbm.xml
=======================================

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

<hibernate-mapping package="com.xxx.commerce.model">

   <subclass name="Product"
      extends="Purchaseable"
      discriminator-value="N"
      >

      <property
         name="height"
         type="com.xxx.commerce.persistence.customtype.CommerceDoubleTypeCustom"
         column="height"
         />
      <property
         name="width"
         type="com.xxx.commerce.persistence.customtype.CommerceDoubleTypeCustom"
         column="width"
         />
      <property
         name="depth"
         type="com.xxx.commerce.persistence.customtype.CommerceDoubleTypeCustom"
         column="depth"
         />

      <set
         name="groups"
         lazy="true"
         cascade="save-update"
         table="purchaseable_group_entry"
         inverse="false"
         >
         <key column="child_id"/>
         <many-to-many class="ProductGroup">
            <column name="parent_id"/>
         </many-to-many>
      </set>
   </subclass>
</hibernate-mapping>

Code between sessionFactory.openSession() and session.close():

Code:

public void testSimple() throws Exception {
   Session session = SessionFactoryUtils.getNewSession((SessionFactory)ObjectFactory.getBean(Constants.SESSION_FACTORY));
   Transaction tx = session.beginTransaction();
   Purchaseable p = (Purchaseable)session.load(Purchaseable.class, new Long(1));
   p.decrementAvailableCount(new Integer(2));
   tx.commit();
}

Full stack trace of any exception that occurs: No exception.

Name and version of the database you are using: mySQL 4.1.11

The generated SQL (show_sql=true):

Code:

16:43:27,619 DEBUG SQL:311 - select purchaseab0_.purchaseable_id as purchase1_0_, purchaseab0_.version as version8_0_, purchaseab0_.group_flag as group2_8_0_, purchaseab0_.name as name8_0_, purchaseab0_.description as descript5_8_0_, purchaseab0_.notes as notes8_0_, purchaseab0_.active_flag as active7_8_0_, purchaseab0_.individually_purchaseable_flag as individu8_8_0_, purchaseab0_.thumbnail as thumbnail8_0_, purchaseab0_.code as code8_0_, purchaseab0_.weight as weight8_0_, purchaseab0_.bargain_price as bargain12_8_0_, purchaseab0_.retail_price as retail13_8_0_, purchaseab0_.ordered_qty as ordered14_8_0_, purchaseab0_.available_qty as available15_8_0_, purchaseab0_.backorder_max_qty as backorder16_8_0_, purchaseab0_.created_by as created17_8_0_, purchaseab0_.created_on as created18_8_0_, purchaseab0_.last_update as last19_8_0_, purchaseab0_.last_update_by as last20_8_0_, purchaseab0_.manufacturer_id as manufac21_8_0_, purchaseab0_.height as height8_0_, purchaseab0_.width as width8_0_, purchaseab0_.depth as depth8_0_, purchaseab0_.separable_flag as separable25_8_0_, purchaseab0_.group_flag as group2_0_ from purchaseable purchaseab0_ where purchaseab0_.purchaseable_id=?

Debug level Hibernate log excerpt:

Code:

43:27,599 DEBUG SessionImpl:248 - opened session at timestamp: 4655447275802624
=========> begin test
43:27,609 DEBUG JDBCTransaction:46 - begin
43:27,609 DEBUG AbstractBatcher:422 - opening JDBC connection
43:27,609 DEBUG JDBCTransaction:50 - current autocommit status: true
43:27,609 DEBUG JDBCTransaction:52 - disabling autocommit
43:27,619 DEBUG DefaultLoadEventListener:143 - loading entity: [com.xxx.commerce.model.Purchaseable#1]
43:27,619 DEBUG DefaultLoadEventListener:289 - attempting to resolve: [com.xxx.commerce.model.Purchaseable#1]
43:27,619 DEBUG DefaultLoadEventListener:325 - object not resolved in any cache: [com.xxx.commerce.model.Purchaseable#1]
43:27,619 DEBUG BasicEntityPersister:2457 - Materializing entity: [com.xxx.commerce.model.Purchaseable#1]
43:27,619 DEBUG Loader:1307 - loading entity: [com.xxx.commerce.model.Purchaseable#1]
43:27,619 DEBUG AbstractBatcher:277 - about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
43:27,619 DEBUG SQL:311 - select purchaseab0_.purchaseable_id as purchase1_0_, purchaseab0_.version as version8_0_, purchaseab0_.group_flag as group2_8_0_, purchaseab0_.name as name8_0_, purchaseab0_.description as descript5_8_0_, purchaseab0_.notes as notes8_0_, purchaseab0_.active_flag as active7_8_0_, purchaseab0_.individually_purchaseable_flag as individu8_8_0_, purchaseab0_.thumbnail as thumbnail8_0_, purchaseab0_.code as code8_0_, purchaseab0_.weight as weight8_0_, purchaseab0_.bargain_price as bargain12_8_0_, purchaseab0_.retail_price as retail13_8_0_, purchaseab0_.ordered_qty as ordered14_8_0_, purchaseab0_.available_qty as available15_8_0_, purchaseab0_.backorder_max_qty as backorder16_8_0_, purchaseab0_.created_by as created17_8_0_, purchaseab0_.created_on as created18_8_0_, purchaseab0_.last_update as last19_8_0_, purchaseab0_.last_update_by as last20_8_0_, purchaseab0_.manufacturer_id as manufac21_8_0_, purchaseab0_.height as height8_0_, purchaseab0_.width as width8_0_, purchaseab0_.depth as depth8_0_, purchaseab0_.separable_flag as separable25_8_0_, purchaseab0_.group_flag as group2_0_ from purchaseable purchaseab0_ where purchaseab0_.purchaseable_id=?
43:27,630 DEBUG AbstractBatcher:365 - preparing statement
43:27,640 DEBUG LongType:59 - binding '1' to parameter: 1
43:27,650 DEBUG AbstractBatcher:293 - about to open ResultSet (open ResultSets: 0, globally: 0)
43:27,650 DEBUG Loader:388 - processing result set
43:27,650 DEBUG Loader:393 - result set row: 0

43:27,650 DEBUG Loader:795 - result row: EntityKey[com.xxx.commerce.model.Purchaseable#1]
43:27,660 DEBUG StringType:86 - returning 'N' as column: group2_0_
43:27,660 DEBUG Loader:945 - Initializing object from ResultSet: [com.xxx.commerce.model.Product#1]
43:27,670 DEBUG BasicEntityPersister:1641 - Hydrating entity: [com.xxx.commerce.model.Product#1]
43:27,670 DEBUG IntegerType:86 - returning '4' as column: version8_0_
43:27,670 DEBUG YesNoType:86 - returning 'false' as column: group2_8_0_
43:27,670 DEBUG StringType:86 - returning 'Test Product' as column: name8_0_
43:27,670 DEBUG TextType:86 - returning 'Test Product Description.' as column: descript5_8_0_
43:27,670 DEBUG TextType:86 - returning 'These are some arbitary internal notes that can be sent.' as column: notes8_0_
43:27,670 DEBUG YesNoType:86 - returning 'true' as column: active7_8_0_
43:27,670 DEBUG YesNoType:86 - returning 'true' as column: individu8_8_0_
43:27,680 DEBUG StringType:86 - returning '1135824976532.jpg' as column: thumbnail8_0_
43:27,680 DEBUG StringType:86 - returning '1234' as column: code8_0_
43:27,680 DEBUG IntegerType:86 - returning '5' as column: ordered14_8_0_
43:27,680 DEBUG IntegerType:86 - returning '5' as column: available15_8_0_
43:27,680 DEBUG IntegerType:86 - returning '5' as column: backorder16_8_0_
43:27,680 DEBUG StringType:86 - returning 'admin' as column: created17_8_0_
43:27,690 DEBUG TimestampType:86 - returning '2005-12-28 21:56:02' as column: created18_8_0_
43:27,700 DEBUG TimestampType:86 - returning '2005-12-30 00:01:50' as column: last19_8_0_
43:27,700 DEBUG StringType:86 - returning 'admin' as column: last20_8_0_
43:27,700 DEBUG LongType:86 - returning '4' as column: manufac21_8_0_
43:27,700 DEBUG TwoPhaseLoad:67 - Version: 4
43:27,700 DEBUG Loader:412 - done processing result set (1 rows)
43:27,700 DEBUG AbstractBatcher:300 - about to close ResultSet (open ResultSets: 1, globally: 1)

43:27,700 DEBUG AbstractBatcher:285 - about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
43:27,710 DEBUG AbstractBatcher:403 - closing statement
43:27,710 DEBUG Loader:508 - total objects hydrated: 1
43:27,710 DEBUG TwoPhaseLoad:96 - resolving associations for [com.xxx.commerce.model.Product#1]
43:27,730 DEBUG CollectionLoadContext:134 - creating collection wrapper:[com.xxx.commerce.model.Purchaseable.fileAssets#1]
43:27,740 DEBUG DefaultLoadEventListener:143 - loading entity: [com.xxx.commerce.model.Manufacturer#4]
43:27,740 DEBUG DefaultLoadEventListener:216 - creating new proxy for entity
43:27,740 DEBUG CollectionLoadContext:134 - creating collection wrapper:[com.xxx.commerce.model.Purchaseable.categories#1]
43:27,740 DEBUG CollectionLoadContext:134 - creating collection wrapper:[com.xxx.commerce.model.Product.groups#1]
43:27,740  INFO Product:137 - Setting available quantity for Purchaseable#1 to 5
43:27,740  INFO Product:137 - Setting available quantity for Purchaseable#1 to 5
43:27,740 DEBUG TwoPhaseLoad:167 - done materializing entity [com.xxx.commerce.model.Product#1]
43:27,750 DEBUG PersistenceContext:789 - initializing non-lazy collections
43:27,750 DEBUG Loader:1335 - done entity load

43:27,750  INFO Product:273 - Decrementing available quantity for Purchaseable#1 by 2
43:27,750  INFO Product:137 - Setting available quantity for Purchaseable#1 to 3
43:27,750 DEBUG JDBCTransaction:83 - commit
43:27,750 DEBUG SessionImpl:319 - automatically flushing session
43:27,750 DEBUG AbstractFlushingEventListener:52 - flushing session
43:27,750 DEBUG AbstractFlushingEventListener:102 - processing flush-time cascades
43:27,760 DEBUG Cascades:836 - processing cascade ACTION_SAVE_UPDATE for: com.xxx.commerce.model.Product
43:27,760 DEBUG Cascades:890 - cascade ACTION_SAVE_UPDATE for collection: com.xxx.commerce.model.Purchaseable.fileAssets
43:27,760 DEBUG Cascades:908 - done cascade ACTION_SAVE_UPDATE for collection: com.xxx.commerce.model.Purchaseable.fileAssets
43:27,760 DEBUG Cascades:890 - cascade ACTION_SAVE_UPDATE for collection: com.xxx.commerce.model.Purchaseable.categories
43:27,760 DEBUG Cascades:908 - done cascade ACTION_SAVE_UPDATE for collection: com.xxx.commerce.model.Purchaseable.categories
43:27,760 DEBUG Cascades:890 - cascade ACTION_SAVE_UPDATE for collection: com.xxx.commerce.model.Product.groups
43:27,760 DEBUG Cascades:908 - done cascade ACTION_SAVE_UPDATE for collection: com.xxx.commerce.model.Product.groups
43:27,760 DEBUG Cascades:861 - done processing cascade ACTION_SAVE_UPDATE for: com.xxx.commerce.model.Product
43:27,760 DEBUG AbstractFlushingEventListener:150 - dirty checking collections
43:27,760 DEBUG AbstractFlushingEventListener:167 - Flushing entities and processing referenced collections
43:27,780 DEBUG Collections:140 - Collection found: [com.xxx.commerce.model.Purchaseable.fileAssets#1], was: [com.xxx.commerce.model.Purchaseable.fileAssets#1] (uninitialized)
43:27,780 DEBUG Collections:140 - Collection found: [com.xxx.commerce.model.Purchaseable.categories#1], was: [com.xxx.commerce.model.Purchaseable.categories#1] (uninitialized)
43:27,780 DEBUG Collections:140 - Collection found: [com.xxx.commerce.model.Product.groups#1], was: [com.xxx.commerce.model.Product.groups#1] (uninitialized)
43:27,780 DEBUG AbstractFlushingEventListener:203 - Processing unreferenced collections
43:27,780 DEBUG AbstractFlushingEventListener:217 - Scheduling collection removes/(re)creates/updates
43:27,790 DEBUG AbstractFlushingEventListener:79 - Flushed: 0 insertions, 0 updates, 0 deletions to 1 objects
43:27,790 DEBUG AbstractFlushingEventListener:85 - Flushed: 0 (re)creations, 0 updates, 0 removals to 3 collections
43:27,790 DEBUG Printer:83 - listing entities:

43:27,790 DEBUG Printer:90 - com.xxx.commerce.model.Product{fileAssets=<uninitialized>, width=24.0, manufacturer=com.xxx.commerce.model.Manufacturer#4, lastUpdateBy=admin, categories=<uninitialized>, thumbnailName=1135824976532.jpg, id=1, height=12.0, backorderMaxQuantity=5, name=Test Product, orderedQuantity=5, productCode=1234, active=true, group=false, bargainPrice=1299.0, depth=35.0, notes=These are some arbitary internal notes that can be sent., createdBy=admin, availableQuantity=3, retailPrice=1599.99, version=4, individuallyPurchaseable=true, groups=<uninitialized>, description=Test Product Description., lastUpdate=2005-12-30 00:01:50, createdOn=2005-12-28 21:56:02, weight=125.0}
43:27,790 DEBUG AbstractFlushingEventListener:267 - executing flush
43:27,790 DEBUG AbstractFlushingEventListener:294 - post flush
43:27,800 DEBUG JDBCContext:238 - before transaction completion
43:27,800 DEBUG SessionImpl:368 - before transaction completion
43:27,800 DEBUG JDBCTransaction:173 - re-enabling autocommit
43:27,800 DEBUG JDBCTransaction:96 - committed JDBC Connection
43:27,800 DEBUG JDBCContext:243 - after transaction completion
43:27,800 DEBUG AbstractBatcher:437 - closing JDBC connection (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)
43:27,810 DEBUG SessionImpl:399 - after transaction completion
=========> end test

Top

ertnutler

Post subject: Hibernate says it's updating the entity, but no SQL is issue

Posted: Mon Jan 09, 2006 10:17 am

Newbie

Joined: Wed Mar 23, 2005 9:33 am
Posts: 11

After a little more digging, I notice this output:

09:14:59,914 DEBUG DefaultSaveOrUpdateEventListener:200 - updating detached instance
09:14:59,924 DEBUG DefaultSaveOrUpdateEventListener:246 - updating [com.xxx.commerce.model.Product#1]
09:14:59,924 DEBUG DefaultSaveOrUpdateEventListener:296 - updating [com.xxx.commerce.model.Product#1]

But no SQL update statement is issued. Can somebody please shed some light on this for me? I've spent so much time on this, I'm (gasp!) considering going back to JDBC!

Top

urs_b

Post subject:

Posted: Tue Jan 10, 2006 4:27 am

Regular

Joined: Tue Jan 03, 2006 9:52 am
Posts: 52
Location: Zurich

Not sure if this helps, I am new to hibernate and use the forumn to get more familiar with it.
Did you try a flush() before commit()?
I understand, that an sql statement is only done when absolute necessary (ex. before select).
And flush() forces the update. Just an idea.

Urs

Top

rajasaur

Post subject: Re: no update issued for changed property

Posted: Tue Jan 10, 2006 4:32 am

Senior

Joined: Tue Aug 23, 2005 8:52 am
Posts: 181

ertnutler wrote:

Code:

public void testSimple() throws Exception {
   Transaction tx = session.beginTransaction();
   Purchaseable p = (Purchaseable)session.load(Purchaseable.class, new Long(1));
   p.decrementAvailableCount(new Integer(2));
   tx.commit();
}

You need a

Code:

session.saveOrUpdate(p);

after p.decrementAvailableCount.
Basically you are not asking Hibernate to save or update your persistent object.

Top

ertnutler

Post subject:

Posted: Tue Jan 10, 2006 12:51 pm

Newbie

Joined: Wed Mar 23, 2005 9:33 am
Posts: 11

Thanks for the suggestions. Hibernate flushes the session on commit of the transaction. If you look at the log output, Hibernate is clearly flushing the session.

Also, a saveOrUpdate() call isn't necessary as the object that I'm changing is already present in the session (via the load() call). I've tried it with and without. The behavior is no different.

I'm thinking it's something related to the dirty checking. For some reason, Hibernate doesn't see this instance as dirty, even though it clearly is.

Top

ertnutler

Post subject:

Posted: Tue Jan 10, 2006 3:15 pm

Newbie

Joined: Wed Mar 23, 2005 9:33 am
Posts: 11

I'm such a bonehead. I had an Interceptor registered. It was returning an empty int[] from the findDirty() callback. When I changed that to return null, everything worked fine.

This is clearly documented in the javadoc, but it would have been much easier to find this if Hibernate would issue a debug log statement like "Deferring to custom dirty checking algorithm." That way I would have known something was up, as I had no intention of using a custom dirty checking strategy.

Code:

/**
    * Called from <tt>flush()</tt>. The return value determines whether the entity is updated
    * <ul>
    * <li>an array of property indices - the entity is dirty
    * <li>and empty array - the entity is not dirty
    * <li><tt>null</tt> - use Hibernate's default dirty-checking algorithm
    * </ul>
    * @param entity a persistent entity
    * @return array of dirty property indices or <tt>null</tt> to choose default behaviour
    */

Top

Page 1 of 1

[ 6 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