I have an 8-9 second performace delay with the following query test case and Hibernate configuration. Please note that the table contains over 5M rows, and is accessed via a DB link. When I turn on trace level logging, the delay is occuring in the AbstractBatcher class as it executes the query. The query execution alone takes over 8 seconds to execute. A corresponding JDBC test case that I created takes less than a second to execute. I created the straight JDBC test case by executing the SQL statement that Hibernate generates.
The symptoms keep pointing me back to Hibernate, and specifically to the AbstractBatcher class. If the issue was a missing index or something of that nature, the JDBC version of the query would be slow also. I am using the same Oracle JDBC driver for both Hibernate and the JDBC versions.
Can anybody recommend a method for debugging this? Should I enter a JIRA?
Thanks.
Log messages:
14:35:05,509 TRACE JDBCContext:210 - after transaction begin
14:35:05,509 INFO TestQueryPerformance:60 - Creating criteria...
14:35:05,510 TRACE ThreadLocalSessionContext:300 - allowing proxied method [createCriteria] to proceed to real session
14:35:05,522 INFO TestQueryPerformance:71 - Executing query...
14:35:05,537 DEBUG AbstractBatcher:366 - about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
14:35:05,538 DEBUG SQL:401 - select * from ( select
Hibernate: select * from ( select
14:35:05,539 TRACE AbstractBatcher:484 - preparing statement
14:35:05,766 TRACE StringType:133 - binding 'value6' to parameter: 1
14:35:05,768 TRACE StringType:133 - binding 'value1' to parameter: 2
14:35:05,769 TRACE StringType:133 - binding '%value3%' to parameter: 3
14:35:13,149 DEBUG AbstractBatcher:382 - about to open ResultSet (open ResultSets: 0, globally: 0)
14:35:13,151 TRACE Loader:694 - processing result set
14:35:13,153 DEBUG Loader:699 - result set row: 0
Hibernate version:
3.2.4.sp1.cp03
Config settings:
hibernate.dialect=org.hibernate.dialect.Oracle10gDialect
hibernate.transaction.factory_class=org.hibernate.transaction.JDBCTransactionFactory
hibernate.current_session_context_class=thread
hibernate.cache.provider_class=org.hibernate.cache.NoCacheProvider
Database:
Oracle 10g
Mapping documents:
Code:
<?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>
<class name="mypackage.MyTable" mutable="false" table="mytable@myschema">
<!-- Specify primary key. This is required to run Hibernate queries with criteria. -->
<id name="pkey" type="big_decimal">
<column name="PKEY" precision="22" scale="0" />
</id>
<property name="dbcolumn1" type="string">
<column name="DBCOL1" length="50" />
</property>
<property name="dbcolumn2" type="string">
<column name="DBCOL2" length="30" />
</property>
<property name="dbcolumn3" type="string">
<column name="DBCOL3" length="100" />
</property>
<property name="dbcolumn4" type="string">
<column name="DBCOL4" length="60" />
</property>
<property name="dbcolumn5" type="string">
<column name="DBCOL5" length="45" />
</property>
<property name="dbcolumn6" type="string">
<column name="DBCOL6" length="2" />
</property>
<property name="dbcolumn7" type="string">
<column name="DBCOL7" length="40" />
</property>
<property name="dbcolumn8" type="string">
<column name="DBCOL8" length="10" />
</property>
<property name="dbcolumn9" type="string">
<column name="DBCOL9" length="10" />
</property>
<property name="dbcolumn10" type="java.lang.Long">
<column name="DBCOL10" precision="15" scale="0" />
</property>
<property name="dbcolumn11" type="java.lang.Long">
<column name="DBCOL11" precision="15" scale="0" />
</property>
<property name="dbcolumn12" type="java.lang.Long">
<column name="DBCOL12" precision="15" scale="0" />
</property>
<property name="dbcolumn13" type="string">
<column name="DBCOL13" length="100" />
</property>
<property name="dbcolumn14" type="string">
<column name="DBCOL14" length="40" />
</property>
<property name="dbcolumn15" type="string">
<column name="DBCOL15" length="10" />
</property>
<property name="dbcolumn16" type="string">
<column name="DBCOL16" length="30" />
</property>
<property name="dbcolumn17" type="java.lang.Long">
<column name="DBCOL17" precision="15" scale="0" />
</property>
<property name="dbcolumn18" type="java.lang.Long">
<column name="DBCOL18" precision="15" scale="0" />
</property>
<property name="dbcolumn19" type="string">
<column name="DBCOL19" length="7" />
</property>
<property name="dbcolumn20" type="string">
<column name="DBCOL20" length="7" />
</property>
<property name="dbcolumn21" type="string">
<column name="DBCOL21" length="30" />
</property>
<property name="dbcolumn22" type="string">
<column name="DBCOL22" length="30" />
</property>
</class>
</hibernate-mapping>
Code:
SessionFactory sessionFactory = null;
Session session = null;
Transaction tx = null;
boolean outcome = false;
int maxResults = 5;
try
{
Configuration cfg = new Configuration();
cfg.configure();
sessionFactory = cfg.buildSessionFactory();
session = sessionFactory.getCurrentSession();
tx = session.beginTransaction();
log.info("Creating criteria...");
Criteria crit = session.createCriteria(MyTable.class);
crit.add(Restrictions.eq("dbcolumn6", "value6"));
crit.add(Restrictions.eq("dbcolumn1", "value1"));
crit.add(Restrictions.like("dbcolumn3", "%" + "value3" + "%"));
crit.setFirstResult(0);
crit.setMaxResults(maxResults);
log.info("Executing query...");
long b = Calendar.getInstance().getTimeInMillis();
List<MyTable> results = crit.list();
log.info("done in "+(Calendar.getInstance().getTimeInMillis()-b)+" ms");
tx.commit();
log.info("Results null? " + (results == null));
log.info("Results empty? " + results.isEmpty());
if(!results.isEmpty())
log.info("First element null? " + (results.get(0) == null));
outcome = (results != null && !(results.isEmpty()) && (results.get(0) != null));
}
catch (Exception e)
{
tx.rollback();
e.printStackTrace();
}
finally
{
if(session != null && session.isOpen())
{
session.close();
session = null;
}
}
assertEquals(true,outcome);
Login
FAQ
Search