For our report UI we query the sessions object and list it in the screen. To query the data we use Hibernate
and a Generic Dao implementation. Before use Dynatrace we always blame database about this query but after start to use DynaTrace it shows us that the bottleneck is in the code at QueryImpl.list method. We have really bad performance both Prod and Dev, The total count records are about 2M in PROD and it takes 75 seconds(yes more than 1 minute :( ) Below screenshots show the Dynatrace Screenshots which show us problem is in Hibernate QueryImpl list method. I checked the application in DEV environment with 500K records and it takes 30 seconds in DEV too and same methods takes the 28 seconds at this query. I track the application get heap dump and analyze in dynatrace and jvisualvm. Also check thread dumps both at samurai and dyntarace but can not find any locked Thread or a lot of special class instance. I share dynatrace pure paths screenshots and our method call which use Spring @Transactional
annotation.
ReadOnly.java
@Target({ ElementType.METHOD, ElementType.TYPE })
@Retention(RetentionPolicy.RUNTIME)
@Transactional(readOnly = true)
public @interface ReadOnly {
}
SessionService.java
@Override
@ReadOnly
public SearchResult<Session> getReport(ISearch search) {
return sessionDao.searchAndCount(search);
}
SessionDao.java
public <RT> SearchResult<RT> searchAndCount(ISearch search) {
if (search == null) {
SearchResult<RT> result = new SearchResult<RT>();
result.setResult((List<RT>) getAll());
result.setTotalCount(result.getResult().size());
return result;
}
return searchAndCount(persistentClass, search);
}
I spend 2-3 days to investigate this problem and i really want to learn the reason.
EDIT: I query 50 records form a 2M table, i use pagination approach and in screenshots i mentioned that it takes 2.5 seconds in database but it spends 75 seconds in memory QueryImpl list method. So I already query 50 records from 2M table which has index in date fields. Please check screenshot red rectangulars.
First of all thanks @M.Deinum for his comments which help us to address the problem. Problem is described at below SO questions :
In my case first running and takes 75 seconds at PROD query is below.
SessionWithJOINFETCH.sql
SELECT
session0.*,
cardholder0.*,
transaction0.*
FROM
MSU_SESSION session0 LEFT OUTER JOIN MSU_CARD_HOLDER cardholder0
ON session0.card_holder_id = cardholder0_.id LEFT OUTER JOIN MSU_TRANSACTION transaction0
ON session0.id = transaction0_.session_id
WHERE
(
session0.status IN(
? ,
?
)
)
AND(
session0.sessionType IS NULL
OR session0.sessionType IN(
? ,
?
)
)
AND session0.session_create_timestamp >= ?
AND session0.session_create_timestamp <= ?
ORDER BY
session0.session_create_timestamp DESC
and also in log i see that WARNING:
firstResult/maxResults specified with collection fetch; applying in memory!
It means we use pagination(for Oracle rowNum) in memory. It can be seen at first runnig sql it hasn't any rowNum, it gets all the data according to criteria and then "firstResult/maxResults specified with collection fetch; applying in memory!" applying firstResult/maxResult in memory and it takes time.
The reason is we are using JOIN FETCH
with setMaxResult
. According to Hibernate forums and above SO question links it is a hibernate feature so you shouldn't be use setMaxResult
with JOIN FETCH
(at least with 1-N relation) after remove this relation below sql is created by hibernate and its performance is better better now.
AfterRemoveJOINFETCH.sql
SELECT
*
FROM
(
SELECT
session0_.*
FROM
MSU_SESSION session0_
WHERE
(
session0_.status IN(
? ,
?
)
)
AND(
session0_.sessionType IS NULL
OR session0_.sessionType IN(
? ,
?
)
)
AND session0_.session_create_timestamp >= ?
AND session0_.session_create_timestamp <= ?
ORDER BY
session0_.session_create_timestamp DESC
)
WHERE
rownum <= ?
I don't know why it is created an inner sql but its performance is better than before now you can see rownum
is added to query and pagination is done at DB level.
firstResult/maxResults specified with collection fetch; applying in memory!
warning is disappered too.