Simple hibernate query returning very slowly

Viewed 57329

I have the following hibernate query:

Query query = session.createQuery("from MyHibernateClass");
List<MyHibernateClass> result = query.list();// executes in 7000ms

When logging the sql being executed in MySQL I see

select 
  myhibernat0_.myFirstColumn as myfirstcolumn92_, 
  myhibernat0_.mySecondColumn as mysecondcolumn92_, 
  myhibernat0_.mythirdcolumn as mythirdcolumn92_, 
  myhibernat0_.myFourthColumn as myfourthcolumn92_ 
from MyHibernateClass myhibernat0_ 
where (1=1);

When measurering the java code in the jvm on a small dataset of 3500 rows in MyHibernateClass database table this takes about 7000ms.

If I on the otherhand uses direct jdbc as follows:

Statement statement = session.connection().createStatement();
ResultSet rs = statement.executeQuery("select * from MyHibernateClass");// 7ms
List<MyHibernateClass> result = convert(rs);// executes in 20ms

I see the same sql going into the database but now the time spend in the java code in the jvm is 7ms.

The MyHibernateClass is a simple java bean class with getters and setters, I use no special resulttransformers as can be seen in the example. I only need a read-only instance of the class, and it doesn't need to be attached to the hibernate session.

I would rather like to use the hibernate version but cannot accept the execution times.

Added information: After adding hibernate logging I see

[2011-07-07 14:26:26,643]DEBUG [main] [logid: ] - 
  org.hibernate.jdbc.AbstractBatcher.logOpenResults(AbstractBatcher.java:426) - 
  about to open ResultSet (open ResultSets: 0, globally: 0)

followed by 3500 of the following log statements

[2011-07-07 14:26:26,649]DEBUG [main] [logid: ] - 
  org.hibernate.loader.Loader.getRow(Loader.java:1197) - 
  result row: EntityKey[com.mycom.MyHibernateClass#1]

followed by 3500 log statements like

[2011-07-07 14:27:06,789]DEBUG [main] [logid: ] - 
  org.hibernate.engine.TwoPhaseLoad.initializeEntity(TwoPhaseLoad.java:130) - 
  resolving associations for [com.mycom.MyHibernateClass#1]
[2011-07-07 14:27:06,792]DEBUG [main] [logid: ] - 
  org.hibernate.engine.TwoPhaseLoad.initializeEntity(TwoPhaseLoad.java:226) - 
  done materializing entity [com.mycom.MyHibernateClass#1]

What does this mean?

What is Hibernate doing in the first implementation, how can I find out?

8 Answers

Anyone else who is facing a similar issue with SQL Server can use sendStringParametersAsUnicode=false in the JDBC Query String as shown in this answer:

JPA (Hibernate) Native Query for Prepared Statement SLOW

If you're not using Unicode for your prepared statement parameters and want to utilize the index on the varchar field which you're using as a parameter for the prepared statement, this can help.

Related