Hi,

Hibernate version:
2.1.7
Mapping documents:

Code between sessionFactory.openSession() and session.close():

Query query =SessionContext.currentSession().getNamedQuery("query");

query.setParameter("active", new Boolean(true));
query.setParameterList("id", stepsLong);
Calendar calendar = Calendar.getInstance();
calendar.set(1975, 01, 01);
query.setParameter("createDate", calendar.getTime());

return (EntityOne[]) query.list().toArray(new EntityOne[0]);

Full stack trace of any exception that occurs:

N/A

Name and version of the database you are using:

SQL Server 2000

The generated SQL (show_sql=true):

N/A

Debug level Hibernate log excerpt:

N/A

I have this HQL query:

SELECT entiryOne
FROM EntiryOne AS entiryOne
INNER JOIN FETCH entiryOne.entityTwo AS entityTwo
INNER JOIN FETCH entiryOne.entityThree AS entityThree
INNER JOIN FETCH entiryOne.entityFour AS entityFour
INNER JOIN entiryOne.entityFive AS entityFive
INNER JOIN entityFive.entitySix AS entitySix
WHERE
entiryOne.active = :active AND
entitySix.id = :id AND
entiryOne.createDate > :createDate
ORDER BY
entiryOne.entityFour, entiryOne.createDate DESC

Seeing the translation, I execute it in the Query Analyzer and it returs in no more than 2 seconds. However, when I do this query from the system, its time goes from 10 to 20 seconds.

This query returns 800 rows. When having less rows, it approximates a lot more to the DMBS times.

Anyone had this problem? What should I do ?

Thanks,
bye.

memory? network? first level cache? this is not so difficult to understand ;)

Hi !! thanks for answering !!

No memory problems (memory stays constant, and the resultset is not that large... only 800 rows)
No network problems... in fact i'm doing the query from the same development pc than it is used for the query analyzer.

but, first level cache? what do you mean by that ? is there something I should do for the first level cache ? I tried writing a session.clear() before the query, but it had no influence on the resulting time (which is correct, I think)

More than likely, Hibernate is loading dependent objects. Turn on SQL logging and see what all is really getting executed.

Hi, thanks for your answer.

I checked that, and although Hibernate was getting two or three additional objects, it didn't seem to me that it could complicate matters. However, I did a little example on this particular case.

I made a reporting query, that is as follows:

<query name="findCalls"><![CDATA[
SELECT new ar.com.tsoluciones.emergencies.service.dto.CallApprovableSimpleView
(
callApprovable.id,
callApprovable.createDate,
incidentType.description,
currentSteps.stepId,
incidentTown.description,
incidentStreet.name,
callApprovable.incidentStreetAppartment,
priority.description,
priority.id
)
FROM CallApprovable AS callApprovable
INNER JOIN callApprovable.incidentSubtype AS incidentSubtype
INNER JOIN incidentSubtype.incidentType AS incidentType
INNER JOIN callApprovable.incidentStreet AS incidentStreet
INNER JOIN incidentStreet.town AS incidentTown
INNER JOIN callApprovable.priority AS priority,
com.opensymphony.workflow.spi.WorkflowEntry AS workflowEntry
INNER JOIN workflowEntry.currentSteps AS currentSteps
WHERE
callApprovable.workflowEntryId = workflowEntry.id AND
currentSteps.stepId IN (:id) AND
callApprovable.active = :active AND
callApprovable.createDate > :createDate
ORDER BY
callApprovable.priority, callApprovable.createDate DESC
]]></query>

THis query, when executed with this code:

Query query = SessionContext.currentSession().getNamedQuery("findCalls");

query.setParameter("active", new Boolean(true));
query.setParameterList("id", new Long[] { new Long(1), new Long(3) });
// No limitar consulta
Calendar calendar = Calendar.getInstance();
calendar.set(1975, 01, 01);
query.setParameter("createDate", calendar.getTime());

return (CallApprovableSimpleView[]) query.list().toArray(new CallApprovableSimpleView[0]);


Takes more than 8000 milliseconds.

I copied the SQL generated by Hibernate using P6Spy, and made a pure JDBC call using that SQL:

Statement statement = SessionContext.currentSession().connection().createStatement();

ResultSet resultSet = statement.executeQuery("SELECT\n" +
" callapprov0_.call_approvable_id AS x0_0_,\n" +
" callapprov0__1_.create_date AS x1_0_,\n" +
" incidentty2_.description AS x2_0_,\n" +
" currentste7_.step_id AS x3_0_,\n" +
" town4_.description AS x4_0_,\n" +
" street3_.name AS x5_0_,\n" +
" callapprov0_.incident_street_appartment AS x6_0_,\n" +
" priority5_.description AS x7_0_,\n" +
" priority5_.id AS x8_0_ FROM\n" +
" tea_call_approvable callapprov0_ inner join tea_os_approvable callapprov0__1_ ON\n" +
" callapprov0_.call_approvable_id=callapprov0__1_.id inner join tea_incident_subtype incidentsu1_ ON\n" +
" callapprov0_.incident_subtype=incidentsu1_.id inner join tea_incident_type incidentty2_ ON\n" +
" incidentsu1_.incident_type=incidentty2_.id inner join tea_street street3_ ON\n" +
" callapprov0_.incident_street=street3_.id inner join tea_town town4_ ON\n" +
" street3_.town=town4_.id inner join tea_priority priority5_ ON\n" +
" callapprov0_.priority=priority5_.id,\n" +
" tea_o_s_wfentry hibernatew6_ inner join tea_o_s_currentstep currentste7_ ON\n" +
" hibernatew6_.id=currentste7_.entry_id WHERE\n" +
" (callapprov0__1_.workflow_entry_id=hibernatew6_.id ) AND\n" +
" (currentste7_.step_id IN(1 ,\n" +
" 3)) AND\n" +
" (callapprov0__1_.active='1') AND\n" +
" (callapprov0__1_.create_date>'1975-02-01 17:11:50.546' )\n" +
" ORDER BY priority5_.id ,\n" +
" callapprov0__1_.create_date DESC");

List list = new ArrayList(100);
while (resultSet.next())
{
CallApprovableSimpleView callApprovableSimpleView = new CallApprovableSimpleView();

callApprovableSimpleView.setId(new Long(resultSet.getLong(1)));
callApprovableSimpleView.setCreateDate(resultSet.getDate(2));
callApprovableSimpleView.setIncidentType(resultSet.getString(3));
callApprovableSimpleView.setStepId(resultSet.getInt(4));
callApprovableSimpleView.setTown(resultSet.getString(5));
callApprovableSimpleView.setIncidentStreet(resultSet.getString(6));
callApprovableSimpleView.setAppartment(resultSet.getString(7));
callApprovableSimpleView.setPriority(resultSet.getString(8));
callApprovableSimpleView.setPriorityId(new Long(resultSet.getLong(9)));

list.add(callApprovableSimpleView);
}

return (CallApprovableSimpleView[]) list.toArray(new CallApprovableSimpleView[0]);


This call takes only 4000 milliseconds.
Why do I multiply the time when going through Hibernate ? What am I doing wrong ? Something in the code ? hibernate configuration ?