-->
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.

All times are UTC - 5 hours [ DST ]



Forum locked This topic is locked, you cannot edit posts or make further replies.  [ 6 posts ] 
Author Message
 Post subject: What is causing these redundant updates?
PostPosted: Sun Jun 02, 2013 8:39 am 
Newbie

Joined: Thu Feb 21, 2013 2:31 pm
Posts: 4
Location: Mumbai, India
I have the following piece of code:

Code:
public int makePayment(User forUser, Collection<Movie> cartItems, Address deliverTo)
{
   int returnCode = 0;

   LOGGER.debug("Number of items in cart - {}", cartItems.size());

   Rental rental = new Rental();
   rental.setRentalID(RandomStringUtils.randomAlphanumeric(ID_LENGTH).toUpperCase());
   rental.setUser(forUser); // Update reference to parent
   rental.setAddress(deliverTo);

   // Each rental has its own set of rented movies
   Set<RentedMovie> rentedMovies = new HashSet<>(cartItems.size());
   for (Iterator<Movie> iterator = cartItems.iterator(); iterator.hasNext();)
   {
      Movie movie = iterator.next();
      RentedMovie rentedMovie = new RentedMovie();
      rentedMovie.setMovie(movie);
      rentedMovie.setRental(rental); // Update reference to parent
      rentedMovies.add(rentedMovie);
   }

   rental.setRentedMovies(rentedMovies);
   rentalDAO.create(rental);

   Set<Rental> userRentals = userDAO.findById(forUser.getUserID()).getRentals();
   userRentals.add(rental); // Add to existing set of rentals

   try
   {
      String addressID = addressDAO.create(deliverTo);
      LOGGER.debug("Delivery Address successfully inserted. Generated address ID - {}", addressID);

      forUser.setRentals(userRentals);
      userDAO.update(forUser); // internally calls getSession().merge();
   }
   catch (Exception e) {
      returnCode = -1;
      LOGGER.error("Exception during payment - {}", e.getMessage(), e);
   }

   return returnCode;
}


Now when the above method completes, hibernate performs certain redundant update queries as described below:

Let's say I add 2 items to cart, so...
Code:
DEBUG PaymentService - Number of items in cart - 2


Next, a row is inserted in RENTALS table (expected)
Code:
insert into rentals(bookingDate, userID, addressID, rentalID) values(?, ?, ?, ?)


USER and ADDRESS table updated once since 1 row inserted in RENTALS (redundant)
Code:
update users set userName=?, password=?, firstName=?, lastName=?, email=?, addressID=? where userID=?
update addresses set line1=?, line2=?, city=?, state=?, pincode=? where addressID=?


MOVIES table updated as many times as the number of items in cart (2 in this case, again redundant)
Code:
update movies set movieName=?, releaseYear=?, rating=?, nCopies=?, imageUri=?, plotLine=? where movieID=?
/* And another query with different movieID */


2 records inserted in RENTED_MOVIE table (expected)
Code:
insert into rented_movie(rentalID, returnDate, movieID) values(?, ?, ?)
/* And one more with same rentalID and diff. movieID */


And last, but not the least, a select query to RENTALS table (Why??)

What is the reason for the above mentioned redundant queries?

I am using Hibernate 4.2.1 with MySQL 5.5

My schema diagram is as follows:

Image

User.hbm.xml
Code:
<class name="User" table="users" dynamic-insert="true" dynamic-update="true">
   
   <id column="userID" name="userID" type="string">
      <generator class="com.clixflix.generators.EntityIDGenerator" />
   </id>
   <property name="userName" column="userName" type="string" not-null="true" length="15" />
   <property name="encrPass" column="password" type="string" not-null="true" />
   <property name="firstName" column="firstName" type="string" not-null="true" length="15" />
   <property name="lastName" column="lastName" type="string" length="20" />
   <property name="email" column="email" type="string" length="45" />
   
   <!-- 1:1 mapping with Address table. -->
   <many-to-one name="address"
         column="addressID"
         class="Address"
         cascade="all"
         unique="true"
         not-null="false"
         not-found="ignore"/> <!-- Address for a User is optional. So ignore if not found. -->

    <!--  1:n mapping with Rental table. -->
    <set name="rentals" table="rentals" inverse="true" cascade="all" lazy="true">
       <key column="userID" not-null="true"/>
       <one-to-many class="Rental"/>
    </set>
   
</class>


Rental.hbm.xml
Code:
<class name="Rental" table="rentals" dynamic-insert="true" dynamic-update="true">
   
   <id name="rentalID" column="rentalID" type="string">
      <generator class="assigned"/>
   </id>
   
   <property name="bookingDate" column="bookingDate" type="date" not-null="true"/>
   
   <!-- n:1 mapping with User -->
   <many-to-one name="user"
      column="userID"
      class="User"
      not-null="true"
      fetch="join"
      cascade="all"/>
   
   <!-- 1:1 mapping with Address -->   
   <many-to-one name="address"
         column="addressID"
         class="Address"
         cascade="all"
         unique="true"
         not-null="true"/>
         
   <!-- m:n mapping with Movie -->
   <set name="rentedMovies" table="rented_movie" lazy="true" cascade="all">
      <key column="rentalID"/>
      <composite-element class="RentedMovie">
         <property name="returnDate" column="returnDate" type="date" not-null="true"/>
         <many-to-one name="movie" column="movieID" class="Movie" not-null="true" cascade="all"/>
      </composite-element>
   </set>
   
</class>


Top
 Profile  
 
 Post subject: Re: What is causing these redundant updates?
PostPosted: Wed Jun 05, 2013 8:25 am 
Expert
Expert

Joined: Tue Jun 16, 2009 3:36 am
Posts: 990
I suggest you to log jdbc avtivity with a jdbcLogger like p6spy.
In this way you see also the parameters of the queries.
Are the parameters exactly the same on the queries you mention redundant?


Top
 Profile  
 
 Post subject: Re: What is causing these redundant updates?
PostPosted: Wed Jun 05, 2013 11:17 am 
Newbie

Joined: Thu Feb 21, 2013 2:31 pm
Posts: 4
Location: Mumbai, India
pb00067 wrote:
I suggest you to log jdbc avtivity with a jdbcLogger like p6spy.
In this way you see also the parameters of the queries.
Are the parameters exactly the same on the queries you mention redundant?


Yes, the parameters are exactly the same. The database snaps and the query log are as below:

Image

Image

Image

Code:
DEBUG PaymentService - Number of items in cart - 1

DEBUG SQL -
    /* load one-to-many com.clixflix.enitities.User.rentals */
    select
        rentals0_.userID as userID3_6_1_,
        rentals0_.rentalID as rentalID1_4_1_,
        rentals0_.rentalID as rentalID1_4_0_,
        rentals0_.bookingDate as bookingD2_4_0_,
        rentals0_.userID as userID3_4_0_,
        rentals0_.addressID as addressI4_4_0_
    from
        rentals rentals0_
    where
        rentals0_.userID=?

TRACE BasicBinder - binding parameter [1] as [VARCHAR] - 3860891409
DEBUG PaymentService - Delivery Address successfully inserted. Generated address ID - 0827554905

DEBUG SQL -
    /* insert com.clixflix.enitities.Rental */
        insert
        into
            rentals
            (bookingDate, userID, addressID, rentalID)
        values
            (?, ?, ?, ?)

TRACE BasicBinder - binding parameter [1] as [DATE] - Wed Jun 05 20:07:04 IST 2013
TRACE BasicBinder - binding parameter [2] as [VARCHAR] - 3860891409
TRACE BasicBinder - binding parameter [3] as [VARCHAR] - 0827554905
TRACE BasicBinder - binding parameter [4] as [VARCHAR] - RM893RE3SCFOX8L

DEBUG SQL -
    /* update com.clixflix.enitities.User */
        update
            users
        set
            userName=?,
            password=?,
            firstName=?,
            lastName=?,
            email=?,
            addressID=?
        where
            userID=?
           
TRACE BasicBinder - binding parameter [1] as [VARCHAR] - admin
TRACE BasicBinder - binding parameter [2] as [VARCHAR] - JMahqnmMkczM1FQy6vxA5WenVQ4WWez+HJ8Hln8zank=$yRyXTp9kGMVLlluOsc6FB4se1lg=
TRACE BasicBinder - binding parameter [3] as [VARCHAR] - Administrator
TRACE BasicBinder - binding parameter [4] as [VARCHAR] - <null>
TRACE BasicBinder - binding parameter [5] as [VARCHAR] - <null>
TRACE BasicBinder - binding parameter [6] as [VARCHAR] - 0827554905
TRACE BasicBinder - binding parameter [7] as [VARCHAR] - 3860891409

DEBUG SQL -
    /* update com.clixflix.enitities.Address */
        update
            addresses
        set
            line1=?,
            line2=?,
            city=?,
            state=?,
            pincode=?
        where
            addressID=?
           
TRACE BasicBinder - binding parameter [1] as [VARCHAR] - Line1
TRACE BasicBinder - binding parameter [2] as [VARCHAR] - Line2
TRACE BasicBinder - binding parameter [3] as [VARCHAR] - City
TRACE BasicBinder - binding parameter [4] as [VARCHAR] - State
TRACE BasicBinder - binding parameter [5] as [VARCHAR] - 400068
TRACE BasicBinder - binding parameter [6] as [VARCHAR] - 0827554905

DEBUG SQL -
    /* update com.clixflix.enitities.Movie */
        update
            movies
        set
            movieName=?,
            releaseYear=?,
            rating=?,
            nCopies=?,
            imageUri=?,
            plotLine=?
        where
            movieID=?
           
TRACE BasicBinder - binding parameter [1] as [VARCHAR] - 300
TRACE BasicBinder - binding parameter [2] as [VARCHAR] - 2007
TRACE BasicBinder - binding parameter [3] as [INTEGER] - 8
TRACE BasicBinder - binding parameter [4] as [INTEGER] - 67
TRACE BasicBinder - binding parameter [5] as [VARCHAR] - pics/300.jpg
TRACE BasicBinder - binding parameter [6] as [VARCHAR] - Based on Frank Miller's graphic novel about the Battle of Thermopylae in 480 B.C.
TRACE BasicBinder - binding parameter [7] as [INTEGER] - 1

DEBUG SQL -
    /* insert collection row com.clixflix.enitities.Rental.rentedMovies */
        insert
        into
            rented_movie
            (rentalID, returnDate, movieID)
        values
            (?, ?, ?)
           
TRACE BasicBinder - binding parameter [1] as [VARCHAR] - RM893RE3SCFOX8L
TRACE BasicBinder - binding parameter [2] as [DATE] - Thu Jan 01 00:00:00 IST 1970
TRACE BasicBinder - binding parameter [3] as [INTEGER] - 1


Top
 Profile  
 
 Post subject: Re: What is causing these redundant updates?
PostPosted: Thu Jun 06, 2013 4:30 am 
Expert
Expert

Joined: Tue Jun 16, 2009 3:36 am
Posts: 990
I don't understand,
the Log you report in your last post seem to not contain redundant sql's at all, not?


Top
 Profile  
 
 Post subject: Re: What is causing these redundant updates?
PostPosted: Thu Jun 06, 2013 4:36 am 
Newbie

Joined: Thu Feb 21, 2013 2:31 pm
Posts: 4
Location: Mumbai, India
pb00067 wrote:
I don't understand,
the Log you report in your last post seem to not contain redundant sql's at all, not?


Code:
update
users
set
   userName=?,
   password=?,
   firstName=?,
   lastName=?,
   email=?,
   addressID=?
where
   userID=?
           
TRACE BasicBinder - binding parameter [1] as [VARCHAR] - admin
TRACE BasicBinder - binding parameter [2] as [VARCHAR] - JMahqnmMkczM1FQy6vxA5WenVQ4WWez+HJ8Hln8zank=$yRyXTp9kGMVLlluOsc6FB4se1lg=
TRACE BasicBinder - binding parameter [3] as [VARCHAR] - Administrator
TRACE BasicBinder - binding parameter [4] as [VARCHAR] - <null>
TRACE BasicBinder - binding parameter [5] as [VARCHAR] - <null>
TRACE BasicBinder - binding parameter [6] as [VARCHAR] - 0827554905
TRACE BasicBinder - binding parameter [7] as [VARCHAR] - 3860891409


It's updating columns of the USER table with values that are already present in that row. See screenshot of user table and see the values being set in the parameters, they are both same. How is this not redundant? Similar is the case for ADDRESS and MOVIE table.


Top
 Profile  
 
 Post subject: Re: What is causing these redundant updates?
PostPosted: Thu Jun 06, 2013 8:30 am 
Expert
Expert

Joined: Tue Jun 16, 2009 3:36 am
Posts: 990
Quote:
It's updating columns of the USER table with values that are already present in that row.

In my understanding the word redundancy has another meaning, so first I meant you experienced multiple sql's doing exactly the same.
Anyway now I understand what you mean.

Unfortunately I do not know why it is happening.
At first I would check following:
- check if the is some explicite lock call which triggers the updates (LockMode.UPGRADE or FORCE)
- do a try without dynamic-update
- do a try without cascade.all (using only the cascade types you need essentially)
- last resort: get the sources of Hibernate 4.2.1 and debug the code and look why hibernate tracks the user as dirty.
You could set a breakpoint to method DefaultFlushEntityEventListener#dirtyCheck
and then discover which are the dirty properties of user.


Top
 Profile  
 
Display posts from previous:  Sort by  
Forum locked This topic is locked, you cannot edit posts or make further replies.  [ 6 posts ] 

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.