Hello:
I am trying to figure out the execution time required to execute an SQL query and get the result set from the Database. Basically, I am using HQL. However, I need to know the time hibernate took to execute the resulting SQL and retrieve the result set.
I executed the generated SQL statement in SQL Plus and the average execution time was around 3 secs. However, the average execution time returned by QueryStatistics is around 27 seconds. Am i correct in assuming that the QueryStatistics returns the time taken to translate the HQL to SQL, execute the SQL, Retrieve the result set and transform the result set to the mapped objects? How do I figure out the actual time taken by hibernate to execute the SQL and retrieve the result set? Better yet, is it possible to figure out the time taken by hibernate for each of the individual steps that I mentioned above?
I have posted some of the details below. I am using hibernate with SpringFramework 1.2.8.
Thanks
Deepak
Hibernate version: 3.05
Code between sessionFactory.openSession() and session.close():
Code:
final StringBuffer hql = new StringBuffer();
hql.append("from AssignmentImpl assgn ");
if (sortColumn != null && sortColumn.trim().length() > 0) {
hql.append(" order by upper(assgn.").append(sortColumn.trim())
.append(") ");
if (sortOrder != null && sortOrder.trim().length() > 0) {
hql.append(sortOrder.trim());
} else {
hql.append(Constants.SORT_ORDER_ASCENDING);
}
}
logger.log(CAPLog.DEBUG, "getAllAssignments", "Hibernate Query: "
+ hql.toString());
List assignments = null;
try {
assignments = hibernateTemplate
.executeFind(new HibernateCallback() {
public Object doInHibernate(Session session)
throws HibernateException, SQLException {
return session.createQuery(hql.toString())
.setFirstResult(startRecord).setMaxResults(
numberOfRecords).list();
}
});
} catch (Exception e) {
logger.log("getAllAssignments", e);
throw new SystemException(e.getMessage(), e);
}
Statistics s = this.hibernateTemplate.getSessionFactory().getStatistics();
String[] queries = s.getQueries();
for (int i = 0; i < queries.length; i++) {
System.out.println(queries[i]);
long et = s.getQueryStatistics(queries[i]).getExecutionAvgTime();
System.out.println("\tAverage ET = " + et);
et = s.getQueryStatistics(queries[i]).getExecutionMaxTime();
System.out.println("\tMax ET " + et);
et= s.getQueryStatistics(queries[i]).getExecutionMinTime();
System.out.println("\tMin ET " + et);
}
return assignments;
Name and version of the database you are using: Oracle9i Release 9.2.0.6.0The generated SQL (show_sql=true):Code:
select * from ( select row_.*, rownum rownum_ from ( select assignment0_.AssignmentID as Assignme1_, assignment0_.AssignmentStatus as Assignme2_16_, assignment0_.AssignmentMappingStatus as Assignme3_16_, assignment0_.AssignmentReviewStatus as Assignme4_16_, assignment0_.AssignmentNumIssues as Assignme5_16_, assignment0_.AssignmentReviewedByMgr as Assignme6_16_, assignment0_.AssignmentReviewedByRevwr as Assignme7_16_, assignment0_.AssignmentReviewerID as Assignme8_16_, assignment0_.AssignmentMapperID as Assignme9_16_, assignment0_.AssignmentCreateDt as Assignm10_16_, assignment0_.AssignmentAssignMapperDt as Assignm11_16_, assignment0_.AssignmentMapperDueDt as Assignm12_16_, assignment0_.AssignmentMappedDt as Assignm13_16_, assignment0_.AssignmentAssignReviewerDt as Assignm14_16_, assignment0_.AssignmentReviewerDueDt as Assignm15_16_, assignment0_.AssignmentReviewedDt as Assignm16_16_, assignment0_.AssignmentCompletedDt as Assignm17_16_, assignment0_.AssignmentConceptsMpdOrRvd as Assignm18_16_, assignment0_.AssignmentConceptsMpd as Assignm19_16_, assignment0_.AssignmentConceptsRvd as Assignm20_16_, assignment0_.AssignmentAssistReqdDt as Assignm21_16_, assignment0_.AssignmentLabel as Assignm22_16_, assignment0_.ReleaseID as ReleaseID16_, assignment0_.AssignmentCreatedBy as Assignm24_16_, assignment0_.LastUpdateDt as LastUpd25_16_, assignment0_.LastUpdateUserID as LastUpd26_16_, assignment0_.UnapprovedCount as Unappro27_16_, assignment0_.TotalCount as TotalCount16_ from MPG_Assignment_View assignment0_, MPG_Release releaseimp1_ where assignment0_.ReleaseID=releaseimp1_.ReleaseID order by upper(releaseimp1_.CrossMapId)asc ) row_ where rownum <= ?) where rownum_ > ?
Debug level Hibernate log excerpt:Code:
from org.cap.snomed.mapping.util.domain.impl.AssignmentImpl assgn order by upper(assgn.release.map.id) asc
Average ExecutionTime = 27136
Max ExecutionTime 27280
Min ExecutionTime 0
Login
FAQ
Search