-->
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
  [ 5 posts ] 
  Previous topic | Next topic 
Author Message
matafleur
 Post subject: slow query performance in springframework
PostPosted: Tue Nov 22, 2005 9:22 am 
Newbie

Joined: Tue Nov 22, 2005 6:09 am
Posts: 3
I have a web application running on apache tomcat 5.0.28 with hibernate and springframework. While i am accessing voucher table (detailed below) via used_by(not primary key, just an ordinary column in my web application, it takes a lot of time. You can see this in the log file below, especially last red lines and beware of the time..

Sometimes it works fast enough but when i add some more rows to the table everything slows down.. For example:
if i have 10K records in the table, it is fast enough to get the records
but when i add extra 10K records and ask for the same records it takes a lot of time.. (231894 msecs for example)

After this, I use the same configuration with a small application, no springframework.. (code is also below) At this time everything works smooth, it takes 60 to 240 msecs to get the records..

I am confused, in my web application it takes more than 3 minutes between these debug lines: (you can see them below in detail..)
15:01:08]- returning '1' as column: x5_0_
15:04:59]- done processing result set (10 rows)

thanks for your consideration and help..

Hibernate version: 2.1.6

Mapping documents:

applicationContext-hibernate.xml

Code:
<beans>
    <bean id="dataSource" class="org.springframework.jdbc.datasource.DriverManagerDataSource">
        <property name="driverClassName"><value>${jdbc.driverClassName}</value></property>
        <property name="url"><value>${jdbc.url}</value></property>
        <property name="username"><value>${jdbc.username}</value></property>
        <property name="password"><value>${jdbc.password}</value></property>
    </bean>

    <bean id="sessionFactory" class="org.springframework.orm.hibernate.LocalSessionFactoryBean">
        <property name="dataSource"><ref bean="dataSource"/></property>
        <property name="mappingResources">
            <list>
            ...
            ...
        </property>
        <property name="hibernateProperties">
            <props>
              <prop key="hibernate.use_outer_join">false</prop>
              <prop key="hibernate.transaction.factory_class">net.sf.hibernate.transaction.JDBCTransactionFactory</prop>
              <prop key="hibernate.dialect">net.sf.hibernate.dialect.Oracle9Dialect</prop>
              <prop key="hibernate.show_sql">true</prop>
            </props>
        </property>
    </bean>

    <bean id="transactionManager" class="org.springframework.orm.hibernate.HibernateTransactionManager">
        <property name="sessionFactory"><ref bean="sessionFactory"/></property>
    </bean>

    <bean id="voucherDAO" class="XXXXX.dao.hibernate.VoucherDAOHibernate">
        <property name="sessionFactory"><ref bean="sessionFactory"/></property>
    </bean> 
    ...
    ...
</beans>


Voucher.hbm

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

<hibernate-mapping package="XXXXXXX.voucher.map">
<class
  name="Voucher"
  table="VOUCHER"
>
    <id
        name="ticketNo"
        type="java.lang.String"
        column="TICKET_NO"
    >
        <generator class="assigned" />
    </id>

    <property
        name="serialNo"
        type="java.lang.Integer"
        column="SERIAL_NO"
        not-null="true"
        length="11"
    />

    <property
        name="created"
        type="java.lang.Long"
        column="CREATED"
        not-null="true"
        length="16"
    />
    <property
        name="used"
        type="java.lang.Long"
        column="USED"
        length="16"
    />
    <property
        name="usedBy"
        type="java.lang.String"
        column="USED_BY"
        length="12"
    />
    <property
        name="expiry"
        type="java.lang.Long"
        column="EXPIRY"
        length="16"
    />
    <property
        name="serviceProviderId"
        type="java.lang.Integer"
        column="SERVICE_PROVIDER_ID"
        not-null="true"
        length="10"
    />
    <property
        name="voucherValue"
        type="java.lang.Integer"
        column="VOUCHER_VALUE"
        not-null="true"
        length="12"
    />
    <property
        name="creditPeriod"
        type="java.lang.Integer"
        column="CREDIT_PERIOD"
        length="10"
    />
    <property
        name="signatureKey"
        type="java.lang.String"
        column="SIGNATURE_KEY"
        not-null="true"
        length="68"
    />
    <property
        name="commentField"
        type="java.lang.String"
        column="COMMENT_FIELD"
        length="64"
    />
    <property
        name="updateCounter"
        type="java.lang.Integer"
        column="UPDATE_COUNTER"
        length="10"
    />
    <property
        name="creationId"
        type="java.lang.Integer"
        column="CREATION_ID"
        length="9"
    />

    <!-- Associations -->

 
 
    <!-- bi-directional many-to-one association to VoucherBrand -->
    <many-to-one
        name="voucherBrand"
        class="XXXXX.voucher.map.VoucherBrands"
        not-null="true"
    >
        <column name="BRAND" />
    </many-to-one>
    <!-- bi-directional many-to-one association to VoucherStateDesc -->
    <many-to-one
        name="voucherStateDesc"
        class="XXXXX.voucher.map.VoucherStateDesc"
        not-null="true"
    >
        <column name="STATE" />
    </many-to-one>
    <!-- bi-directional many-to-one association to VoucherDistributor -->
    <many-to-one
        name="voucherDistributor"
        class="XXXXX.voucher.map.VoucherDistributors"
        not-null="true"
    >
        <column name="DISTRIBUTOR_ID" />
    </many-to-one>
</class>
</hibernate-mapping>


Code between sessionFactory.openSession() and session.close():
Very Simple Application
Code:
  String q = "SELECT " +
    "v.ticketNo, v.serialNo, v.created, v.used, " +
    "v.voucherValue " +
    "FROM Voucher v " +
    "WHERE v.usedBy = ?";
  long startTime = System.currentTimeMillis();
  List vouchers = session.find(q, "905438959376", Hibernate.STRING);
  long endTime = System.currentTimeMillis();
  System.out.println("voucher size is " + vouchers.size() + " in " + (endTime-startTime) + " msecs.");

SpringFramework, class extending HibernateDaoSupport
Code:
public List getVouchers(String msisdn, long startDate, long endDate) throws Exception {
  String q = "SELECT " +
   "v.ticketNo, v.serialNo, v.created, v.used, " +
   "v.voucherValue " +
   "FROM Voucher v " +
   "WHERE v.usedBy = ? ";
  Session s = getHibernateTemplate().getSessionFactory().openSession();
  long startTime = System.currentTimeMillis();
  List r = s.find(q, msisdn, Hibernate.STRING);
  long endTime = System.currentTimeMillis();
  System.out.println("result size is " + r.size() + " in " + (endTime-startTime) + " msecs.");
  return r;
}

Full stack trace of any exception that occurs:
none
Name and version of the database you are using:Oracle9i Enterprise Edition Release 9.2.0.1.0 - 64bit Production


The generated SQL (show_sql=true):
Very Simple Application
Code:
select voucher0_.TICKET_NO as x0_0_, voucher0_.SERIAL_NO as x1_0_, voucher0_.CREATED as x2_0_, voucher0_.USED as x3_0_, voucher0_.VOUCHER_VALUE as x4_0_ from VOUCHER voucher0_ where (voucher0_.USED_BY=? )


Apache Tomcat 5.0.28, SpringFramework
Code:
Hibernate: select voucher0_.TICKET_NO as x0_0_, voucher0_.SERIAL_NO as x1_0_, vo
ucher0_.CREATED as x2_0_, voucher0_.USED as x3_0_, voucher0_.VOUCHER_VALUE as x4
_0_, voucher0_.BRAND as x5_0_ from VOUCHER voucher0_ where (voucher0_.USED_BY=?)

Debug level Hibernate log excerpt:

Debug Log for SpringFramework, some parts of the log (DEBUG words, dates are removed but no lines are deleted.)

Code:
15:01:07]- opened session
15:01:07]- find: SELECT v.ticketNo, v.serialNo, v.created, v.used, v.voucherValue, v.voucherBrand.brand FROM Voucher v WHERE v.usedBy = ?
15:01:07]- parameters: [905438959377]
15:01:07]- flushing session
15:01:07]- Flushing entities and processing referenced collections
15:01:07]- Processing unreferenced collections
15:01:07]- Scheduling collection removes/(re)creates/updates
15:01:07]- Flushed: 0 insertions, 0 updates, 0 deletions to 0 objects
15:01:07]- Flushed: 0 (re)creations, 0 updates, 0 removals to 0 collections
15:01:07]- Dont need to execute flush
15:01:07]- HQL: SELECT v.ticketNo, v.serialNo, v.created, v.used, v.voucherValue, v.voucherBrand.brand FROM com.oksijen.inox.gui.model.Voucher v WHERE v.usedBy = ?
15:01:07]- SQL: select voucher0_.TICKET_NO as x0_0_, voucher0_.SERIAL_NO as x1_0_, voucher0_.CREATED as x2_0_, voucher0_.USED as x3_0_, voucher0_.VOUCHER_VALUE as x4_0_, voucher0_.BRAND as x5_0_ from VOUCHER voucher0_ where (voucher0_.USED_BY=? )
15:01:07]- about to open: 0 open PreparedStatements, 0 open ResultSets
15:01:08]- select voucher0_.TICKET_NO as x0_0_, voucher0_.SERIAL_NO as x1_0_, voucher0_.CREATED as x2_0_, voucher0_.USED as x3_0_, voucher0_.VOUCHER_VALUE as x4_0_, voucher0_.BRAND as x5_0_ from VOUCHER voucher0_ where (voucher0_.USED_BY=? )
15:01:08]- preparing statement
15:01:08]- binding '905438959377' to parameter: 1
15:01:08]- processing result set
15:01:08]- result row:
15:01:08]- returning '987429774629' as column: x0_0_
15:01:08]- returning '262' as column: x1_0_
15:01:08]- returning '1132583955840' as column: x2_0_
15:01:08]- returning null as column: x3_0_
15:01:08]- returning '5' as column: x4_0_
15:01:08]- returning '1' as column: x5_0_
15:01:08]- result row:
15:01:08]- returning '987406080702' as column: x0_0_
15:01:08]- returning '263' as column: x1_0_
15:01:08]- returning '1132583955841' as column: x2_0_
15:01:08]- returning null as column: x3_0_
15:01:08]- returning '5' as column: x4_0_
15:01:08]- returning '1' as column: x5_0_
15:01:08]- result row:
15:01:08]- returning '987248760659' as column: x0_0_
15:01:08]- returning '264' as column: x1_0_
15:01:08]- returning '1132583955842' as column: x2_0_
15:01:08]- returning null as column: x3_0_
15:01:08]- returning '5' as column: x4_0_
15:01:08]- returning '1' as column: x5_0_
15:01:08]- result row:
15:01:08]- returning '987589999021' as column: x0_0_
15:01:08]- returning '265' as column: x1_0_
15:01:08]- returning '1132583955846' as column: x2_0_
15:01:08]- returning null as column: x3_0_
15:01:08]- returning '5' as column: x4_0_
15:01:08]- returning '1' as column: x5_0_
15:01:08]- result row:
15:01:08]- returning '987842130152' as column: x0_0_
15:01:08]- returning '267' as column: x1_0_
15:01:08]- returning '1132583955850' as column: x2_0_
15:01:08]- returning null as column: x3_0_
15:01:08]- returning '5' as column: x4_0_
15:01:08]- returning '1' as column: x5_0_
15:01:08]- result row:
15:01:08]- returning '987781634882' as column: x0_0_
15:01:08]- returning '268' as column: x1_0_
15:01:08]- returning '1132583955850' as column: x2_0_
15:01:08]- returning null as column: x3_0_
15:01:08]- returning '5' as column: x4_0_
15:01:08]- returning '1' as column: x5_0_
15:01:08]- result row:
15:01:08]- returning '987364700349' as column: x0_0_
15:01:08]- returning '270' as column: x1_0_
15:01:08]- returning '1132583955852' as column: x2_0_
15:01:08]- returning null as column: x3_0_
15:01:08]- returning '5' as column: x4_0_
15:01:08]- returning '1' as column: x5_0_
15:01:08]- result row:
15:01:08]- returning '987316231900' as column: x0_0_
15:01:08]- returning '271' as column: x1_0_
15:01:08]- returning '1132583955855' as column: x2_0_
15:01:08]- returning null as column: x3_0_
15:01:08]- returning '5' as column: x4_0_
15:01:08]- returning '1' as column: x5_0_
15:01:08]- result row:
15:01:08]- returning '987414732265' as column: x0_0_
15:01:08]- returning '272' as column: x1_0_
15:01:08]- returning '1132583955857' as column: x2_0_
15:01:08]- returning null as column: x3_0_
15:01:08]- returning '5' as column: x4_0_
15:01:08]- returning '1' as column: x5_0_
15:01:08]- result row:
15:01:08]- returning '987019390993' as column: x0_0_
15:01:08]- returning '274' as column: x1_0_
15:01:08]- returning '1132583955858' as column: x2_0_
15:01:08]- returning null as column: x3_0_
15:01:08]- returning '5' as column: x4_0_

15:01:08]- returning '1' as column: x5_0_
15:04:59]- done processing result set (10 rows)
15:04:59]- done closing: 0 open PreparedStatements, 0 open ResultSets
15:04:59]- closing statement
15:04:59]- initializing non-lazy collections
Top
 Profile  
 
Rilux
 Post subject:
PostPosted: Tue Nov 22, 2005 9:34 am 
Regular
Regular

Joined: Tue Nov 23, 2004 7:42 am
Posts: 82
Location: London, England
If you are having problems with the Spring Framework then wouldn't it be prudent to ask for help in a Spring forum? You are unlikely to get help with Spring here as it's a Hibernate forum.
Top
 Profile  
 
matafleur
 Post subject:
PostPosted: Tue Nov 22, 2005 9:38 am 
Newbie

Joined: Tue Nov 22, 2005 6:09 am
Posts: 3
i am not sure enough that this problem is caused by springframework; because when i use a similar query on the same table with primary key both springframework side and simple application work fine..
Top
 Profile  
 
CollinL
 Post subject:
PostPosted: Tue Nov 22, 2005 11:13 am 
Regular
Regular

Joined: Wed Feb 02, 2005 6:33 am
Posts: 70
Have you run the SQL on the database yourself? - copy the sql, substitue appropriate values in, and see how long the query itself is taking. If it takes a long time to run the actual sql in the database, then there's nothing hibernate or spring can do to speed that up. If you want it to go faster, you have to change your db design, whether that simply involves specifying a column or set of columns as indexes, or normalising tables.
Top
 Profile  
 
matafleur
 Post subject:
PostPosted: Tue Nov 22, 2005 11:27 am 
Newbie

Joined: Tue Nov 22, 2005 6:09 am
Posts: 3
thanks for the reply; but
of course i have run the query in the database myself when the table had 4000K records not only 20K records.. and result is great.

and i have mentioned when i was asking my question that it works fine with a small hibernate application..
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
  [ 5 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.