I have a really simple problem, I have a query where I get a bunch of PanelSurvey objects, then I want to traverse the results.
It works, but its AWFULLY slow.
Here are the series of event according to hibernate's logging:
1. The select statement to return all the PanelSurvey object is executed (takes about 10 seconds, this is great)
Quote:
FINE: select panelsurve0_.batch_no as batch_no, panelsurve0_.panel_id as panel_id, panelsurve0_.survey_id as survey_id, panelsurve0_.completion_status_id as completi4_, panelsurve0_.start_time as start_time, panelsurve0_.end_time as end_time, panelsurve0_.query_string as query_st7_ from panel_survey panelsurve0_ where (panelsurve0_.survey_id=? )AND(panelsurve0_.batch_no IN(?))AND(panelsurve0_.completion_status_id IN(? , ?))AND(panelsurve0_.panel_id NOT IN(select panelsurve1_.panel_id from panel_survey_email_log panelsurve1_ where (panelsurve1_.email_id=? )AND(panelsurve1_.survey_id=? )AND(panelsurve1_.batch_no IN(?))))
2. As soon as while( scroll.next() ) { is executed, hibernate generates a query and tries to grab a Panel object.
Quote:
FINE: select panel0_.panel_id as panel_id0_, panel0_.removal_type_id as removal_2_0_, panel0_.current_status_id as current_3_0_, panel0_.source_id as source_id0_, panel0_.email as email0_, panel0_.password as password0_, panel0_.last_login_dt as last_log7_0_, panel0_.current_points as current_8_0_, panel0_.prior_points as prior_po9_0_, panel0_.redeemable_points as redeema10_0_, panel0_.invite_dt as invite_dt0_, panel0_.register_dt as registe12_0_, panel0_.removal_dt as removal_dt0_, panel0_.last_mod_dt as last_mo14_0_ from panel panel0_ where panel0_.panel_id=?
Now it SEEMS like it is hanging for about 20 minutes, just waiting for the query to return. This query should takes 1 second at the MOST to return. I have no idea what hibernate is doing or what its waiting for. After a long period of time (~20 minutes), hibernate continues and run the rest of the resultset quickly and perfectly. Its only on that first scroll.next() that hibernate takes an awfully long time.
Could hibernate be trying to resolve some associations at this time?
Could my relationships be setup in an odd way causing hibernate to act weird?
One other oddity I found...the more rows the first query returns the long the scroll.next() takes. I would expect the query.scroll() to take longer. Its so weird that the select of one row it taking A LONG time on the first scroll.next() - every subsequent call runs great though.
Also, all the queries that hibernate generates run VERY fast executing them on the database directly.
If anyone has any idea what could be going on here or what else I can do to find out what is going on here, please let me know.
I can post more of my hbm.xml if it'll help.
Any suggestions are appreciated, I am completely lost here. My next step is to find the exactly line(s) in hibernate that are making my app seem like its 'hanging'.
for what its worth...I think its something in my mapping file causing it to act slow.
Thanks!
Hibernate version: 2.1.7
Mapping documents:
Here is the mapping for PanelSurvey...
<class name="com.lsr.eclipse.framework.database.model.PanelSurvey" table="panel_survey">
<composite-id>
<key-property column="batch_no" length="6" name="batchNo" type="java.lang.Integer"/>
<key-many-to-one column="panel_id" name="panel" class="com.lsr.eclipse.framework.database.model.Panel"/>
<key-many-to-one column="survey_id" name="survey" class="com.lsr.eclipse.framework.database.model.Survey"/>
</composite-id>
<many-to-one column="completion_status_id" name="completionStatus" class="com.lsr.eclipse.framework.database.model.RefCompletionStatus" outer-join="false"/>
<property column="start_time" length="23" name="startTime" type="java.util.Date"/>
<property column="end_time" length="23" name="endTime" type="java.util.Date"/>
<property column="query_string" length="255" name="queryString" type="java.lang.String"/>
</class>
Code between sessionFactory.openSession() and session.close():
Code:
session = core.getDatabase().openSession();
monitor.currentTask("Querying Database...");
// Find panelists who have not been sent an e-mail with
// the requested CompletionStatuses
Query query = session
.createQuery("SELECT panelSurvey FROM PanelSurvey panelSurvey "
+ "WHERE panelSurvey.survey=:survey AND panelSurvey.batchNo IN (:batchNos) "
+ "AND panelSurvey.completionStatus IN (:completionStatuses) AND panelSurvey.panel NOT IN ("
+ "SELECT panelSurveyEmailLog.panel FROM PanelSurveyEmailLog panelSurveyEmailLog "
+ "WHERE panelSurveyEmailLog.email=:email AND panelSurveyEmailLog.survey=:survey "
+ "AND panelSurveyEmailLog.batchNo IN (:batchNos)"
+ ")");
query.setParameterList("completionStatuses",
completionStatuses);
query.setParameter("email", email);
query.setParameter("survey", surveyBatches[0]
.getSurvey());
query.setParameterList("batchNos", batchNos);
ScrollableResults sr = query.scroll();
session.flush();
monitor.tasks(count.intValue());
log.debug("tasks: " + count);
while (sr.next() ) {
PanelSurvey panelSurvey = (PanelSurvey) sr.get(0);
System.exit(0);
.........
Full stack trace of any exception that occurs: None
Name and version of the database you are using: Sybase 12.5
The generated SQL (show_sql=true):
FINE: select panelsurve0_.batch_no as batch_no, panelsurve0_.panel_id as panel_id, panelsurve0_.survey_id as survey_id, panelsurve0_.completion_status_id as completi4_, panelsurve0_.start_time as start_time, panelsurve0_.end_time as end_time, panelsurve0_.query_string as query_st7_ from panel_survey panelsurve0_ where (panelsurve0_.survey_id=? )AND(panelsurve0_.batch_no IN(?))AND(panelsurve0_.completion_status_id IN(? , ?))AND(panelsurve0_.panel_id NOT IN(select panelsurve1_.panel_id from panel_survey_email_log panelsurve1_ where (panelsurve1_.email_id=? )AND(panelsurve1_.survey_id=? )AND(panelsurve1_.batch_no IN(?))))
FINE: select panel0_.panel_id as panel_id0_, panel0_.removal_type_id as removal_2_0_, panel0_.current_status_id as current_3_0_, panel0_.source_id as source_id0_, panel0_.email as email0_, panel0_.password as password0_, panel0_.last_login_dt as last_log7_0_, panel0_.current_points as current_8_0_, panel0_.prior_points as prior_po9_0_, panel0_.redeemable_points as redeema10_0_, panel0_.invite_dt as invite_dt0_, panel0_.register_dt as registe12_0_, panel0_.removal_dt as removal_dt0_, panel0_.last_mod_dt as last_mo14_0_ from panel panel0_ where panel0_.panel_id=?
Debug level Hibernate log excerpt:
Dec 27, 2004 5:07:18 PM net.sf.hibernate.hql.QueryTranslator logQuery
FINE: HQL: SELECT panelSurvey FROM com.lsr.eclipse.framework.database.model.PanelSurvey panelSurvey WHERE panelSurvey.survey=:survey AND panelSurvey.batchNo IN (:batchNos0_) AND panelSurvey.completionStatus IN (:completionStatuses0_, :completionStatuses1_) AND panelSurvey.panel NOT IN (SELECT panelSurveyEmailLog.panel FROM com.lsr.eclipse.framework.database.model.PanelSurveyEmailLog panelSurveyEmailLog WHERE panelSurveyEmailLog.email=:email AND panelSurveyEmailLog.survey=:survey AND panelSurveyEmailLog.batchNo IN (:batchNos0_))
Dec 27, 2004 5:07:18 PM net.sf.hibernate.hql.QueryTranslator logQuery
FINE: SQL: select panelsurve0_.batch_no as batch_no, panelsurve0_.panel_id as panel_id, panelsurve0_.survey_id as survey_id, panelsurve0_.completion_status_id as completi4_, panelsurve0_.start_time as start_time, panelsurve0_.end_time as end_time, panelsurve0_.query_string as query_st7_ from panel_survey panelsurve0_ where (panelsurve0_.survey_id=? )AND(panelsurve0_.batch_no IN(?))AND(panelsurve0_.completion_status_id IN(? , ?))AND(panelsurve0_.panel_id NOT IN(select panelsurve1_.panel_id from panel_survey_email_log panelsurve1_ where (panelsurve1_.email_id=? )AND(panelsurve1_.survey_id=? )AND(panelsurve1_.batch_no IN(?))))
Dec 27, 2004 5:07:18 PM net.sf.hibernate.impl.BatcherImpl log
FINE: select panelsurve0_.batch_no as batch_no, panelsurve0_.panel_id as panel_id, panelsurve0_.survey_id as survey_id, panelsurve0_.completion_status_id as completi4_, panelsurve0_.start_time as start_time, panelsurve0_.end_time as end_time, panelsurve0_.query_string as query_st7_ from panel_survey panelsurve0_ where (panelsurve0_.survey_id=? )AND(panelsurve0_.batch_no IN(?))AND(panelsurve0_.completion_status_id IN(? , ?))AND(panelsurve0_.panel_id NOT IN(select panelsurve1_.panel_id from panel_survey_email_log panelsurve1_ where (panelsurve1_.email_id=? )AND(panelsurve1_.survey_id=? )AND(panelsurve1_.batch_no IN(?))))
Dec 27, 2004 5:07:34 PM net.sf.hibernate.impl.SessionImpl flushEverything
FINE: Flushed: 0 insertions, 0 updates, 0 deletions to 0 objects
Dec 27, 2004 5:07:34 PM net.sf.hibernate.impl.SessionImpl flushEverything
FINE: Flushed: 0 (re)creations, 0 updates, 0 removals to 0 collections
Dec 27, 2004 5:07:34 PM com.lsr.eclipse.swing.moat.InternalFrameSendSurveyBatchEmail$4 run
FINE: tasks: 1107
Dec 27, 2004 5:07:34 PM net.sf.hibernate.impl.BatcherImpl log
FINE: select panel0_.panel_id as panel_id0_, panel0_.removal_type_id as removal_2_0_, panel0_.current_status_id as current_3_0_, panel0_.source_id as source_id0_, panel0_.email as email0_, panel0_.password as password0_, panel0_.last_login_dt as last_log7_0_, panel0_.current_points as current_8_0_, panel0_.prior_points as prior_po9_0_, panel0_.redeemable_points as redeema10_0_, panel0_.invite_dt as invite_dt0_, panel0_.register_dt as registe12_0_, panel0_.removal_dt as removal_dt0_, panel0_.last_mod_dt as last_mo14_0_ from panel panel0_ where panel0_.panel_id=?