Thanks vlad - I've already visited you site many times, but I am still new to this stuff - didn't find much on google about "simple entity query". Can you point me to a more elaborate example?
What I don't understand is how this example can be so slow, like 15 seconds slow for 350 entities, when I know that on other circumstances I can pull 10k of the same entitites in 5 seconds. It is not that the database is slow. The same query is blistering fast in SQL developer.
Scenario:
Load one account where entries are loaded eagerly.
- This goes fine and quick.
Then navigate to the account in the other end of each entry in order to get info about that.
- This triggers the batch-query.
I can battle the problem by pre-requesting the accounts with a specific query instead of relying on batch.
Example
Quick version where I pre-requests all accounts
Code:
Hibernate: -- The request for the account of interest
/* select
A
from
Account A
where
A.accountId = :accountId */ select
*
from
( select
account0_.accountId as accountId1_0_,
account0_.context as context2_0_,
account0_.currency as currency3_0_,
account0_.description as description4_0_,
account0_.name as name5_0_,
account0_.ownerId as ownerId6_0_
from
AUKTIONSMANAGER.tblaccountingaccount account0_
where
account0_.accountId=? )
where
rownum <= ?
Hibernate: -- The pre-request I do to fill 1st lv cache
/*
from
Account
where
accountId in (
select
(case
when TE.fromAccount.accountId = :accountId then TE.toAccount.accountId
else TE.fromAccount.accountId
end)
from
TransferEvent TE
where
TE.eventId in (
select
distinct E.event.eventId
from
Entry E
where
E.account.accountId= :accountId
)
) */ select
account0_.accountId as accountId1_0_,
account0_.context as context2_0_,
account0_.currency as currency3_0_,
account0_.description as description4_0_,
account0_.name as name5_0_,
account0_.ownerId as ownerId6_0_
from
AUKTIONSMANAGER.tblaccountingaccount account0_
where
account0_.accountId in (
select
case
when transferev1_.fromAccountId=? then transferev1_.toAccountId
else transferev1_.fromAccountId
end
from
AUKTIONSMANAGER.tblaccountingtransferevent transferev1_
inner join
AUKTIONSMANAGER.tblaccountingevent transferev1_1_
on transferev1_.eventId=transferev1_1_.eventId
where
transferev1_.eventId in (
select
distinct entry2_.eventId
from
AUKTIONSMANAGER.tblaccountingentry entry2_
where
entry2_.accountId=?
)
)
Hibernate: --- Hibernate magic when I access the entries on the first account.
/* load one-to-many com.autorola.fleetmonitor.accounting.domain.model.account.Account.entries */ select
entries0_.accountId as accountId8_0_4_,
entries0_.entryId as entryId1_3_4_,
entries0_.entryId as entryId1_3_3_,
entries0_.accountId as accountId8_3_3_,
entries0_.amount as amount2_3_3_,
entries0_.currency as currency3_3_3_,
entries0_.deleted as deleted4_3_3_,
entries0_.eventId as eventId9_3_3_,
entries0_.text as text5_3_3_,
entries0_.transactionId as transactionId10_3_3_,
entries0_.whenBooked as whenBooked6_3_3_,
entries0_.whenCharged as whenCharged7_3_3_,
event1_.eventId as eventId1_5_0_,
event1_.baseEventId as baseEventId6_5_0_,
event1_.eventType as eventType2_5_0_,
event1_.origin as origin3_5_0_,
event1_.whenNoticed as whenNoticed4_5_0_,
event1_.whenOccurred as whenOccurred5_5_0_,
event1_1_.toAccountId as toAccountId2_1_0_,
event1_2_.adjustedEventId as adjustedEventId3_2_0_,
event1_2_.isProcessed as isProcessed1_2_0_,
event1_3_.adjustedEventId as adjustedEventId7_8_0_,
event1_3_.amount as amount1_8_0_,
event1_3_.currency as currency2_8_0_,
event1_3_.fromAccountId as fromAccountId8_8_0_,
event1_3_.fromText as fromText3_8_0_,
event1_3_.isProcessed as isProcessed4_8_0_,
event1_3_.replacementEventId as replacementEventId9_8_0_,
event1_3_.toAccountId as toAccountId10_8_0_,
event1_3_.toText as toText5_8_0_,
event1_3_.transactionId as transactionId11_8_0_,
case
when event1_1_.eventId is not null then 1
when event1_2_.eventId is not null then 2
when event1_3_.eventId is not null then 3
when event1_.eventId is not null then 0
end as clazz_0_,
account2_.accountId as accountId1_0_1_,
account2_.context as context2_0_1_,
account2_.currency as currency3_0_1_,
account2_.description as description4_0_1_,
account2_.name as name5_0_1_,
account2_.ownerId as ownerId6_0_1_,
transferev3_.eventId as eventId1_5_2_,
transferev3_1_.baseEventId as baseEventId6_5_2_,
transferev3_1_.eventType as eventType2_5_2_,
transferev3_1_.origin as origin3_5_2_,
transferev3_1_.whenNoticed as whenNoticed4_5_2_,
transferev3_1_.whenOccurred as whenOccurred5_5_2_,
transferev3_.adjustedEventId as adjustedEventId7_8_2_,
transferev3_.amount as amount1_8_2_,
transferev3_.currency as currency2_8_2_,
transferev3_.fromAccountId as fromAccountId8_8_2_,
transferev3_.fromText as fromText3_8_2_,
transferev3_.isProcessed as isProcessed4_8_2_,
transferev3_.replacementEventId as replacementEventId9_8_2_,
transferev3_.toAccountId as toAccountId10_8_2_,
transferev3_.toText as toText5_8_2_,
transferev3_.transactionId as transactionId11_8_2_
from
AUKTIONSMANAGER.tblaccountingentry entries0_
inner join
AUKTIONSMANAGER.tblaccountingevent event1_
on entries0_.eventId=event1_.eventId
left outer join
AUKTIONSMANAGER.tblaccountingapplytempltevent event1_1_
on event1_.eventId=event1_1_.eventId
left outer join
AUKTIONSMANAGER.tblaccountingdeleteentryevent event1_2_
on event1_.eventId=event1_2_.eventId
left outer join
AUKTIONSMANAGER.tblaccountingtransferevent event1_3_
on event1_.eventId=event1_3_.eventId
left outer join
AUKTIONSMANAGER.tblaccountingaccount account2_
on event1_1_.toAccountId=account2_.accountId
left outer join
AUKTIONSMANAGER.tblaccountingtransferevent transferev3_
on event1_2_.adjustedEventId=transferev3_.eventId
left outer join
AUKTIONSMANAGER.tblaccountingevent transferev3_1_
on transferev3_.eventId=transferev3_1_.eventId
where
(
entries0_.deleted = 0
)
and entries0_.accountId=?
2017-03-12 21:18:04,537 INFO [http-bio-24080-exec-8] [org.hibernate.engine.internal.StatisticalLoggingSessionEventListener] Session Metrics {
67764 nanoseconds spent acquiring 1 JDBC connections;
0 nanoseconds spent releasing 0 JDBC connections;
459892 nanoseconds spent preparing 3 JDBC statements;
488948863 nanoseconds spent executing 3 JDBC statements;
0 nanoseconds spent executing 0 JDBC batches;
0 nanoseconds spent performing 0 L2C puts;
0 nanoseconds spent performing 0 L2C hits;
0 nanoseconds spent performing 0 L2C misses;
0 nanoseconds spent executing 0 flushes (flushing a total of 0 entities and 0 collections);
16565 nanoseconds spent executing 2 partial-flushes (flushing a total of 0 entities and 0 collections)
}
Example where I rely on Hibernate Batch.
Code:
Hibernate: -- The request for the account of interest
/* select
A
from
Account A
where
A.accountId = :accountId */ select
*
from
( select
account0_.accountId as accountId1_0_,
account0_.context as context2_0_,
account0_.currency as currency3_0_,
account0_.description as description4_0_,
account0_.name as name5_0_,
account0_.ownerId as ownerId6_0_
from
AUKTIONSMANAGER.tblaccountingaccount account0_
where
account0_.accountId=? )
where
rownum <= ?
Hibernate: --- Hibernate magic when I access the entries on the first account.
/* load one-to-many com.autorola.fleetmonitor.accounting.domain.model.account.Account.entries */ select
entries0_.accountId as accountId8_0_4_,
entries0_.entryId as entryId1_3_4_,
entries0_.entryId as entryId1_3_3_,
entries0_.accountId as accountId8_3_3_,
entries0_.amount as amount2_3_3_,
entries0_.currency as currency3_3_3_,
entries0_.deleted as deleted4_3_3_,
entries0_.eventId as eventId9_3_3_,
entries0_.text as text5_3_3_,
entries0_.transactionId as transactionId10_3_3_,
entries0_.whenBooked as whenBooked6_3_3_,
entries0_.whenCharged as whenCharged7_3_3_,
event1_.eventId as eventId1_5_0_,
event1_.baseEventId as baseEventId6_5_0_,
event1_.eventType as eventType2_5_0_,
event1_.origin as origin3_5_0_,
event1_.whenNoticed as whenNoticed4_5_0_,
event1_.whenOccurred as whenOccurred5_5_0_,
event1_1_.toAccountId as toAccountId2_1_0_,
event1_2_.adjustedEventId as adjustedEventId3_2_0_,
event1_2_.isProcessed as isProcessed1_2_0_,
event1_3_.adjustedEventId as adjustedEventId7_8_0_,
event1_3_.amount as amount1_8_0_,
event1_3_.currency as currency2_8_0_,
event1_3_.fromAccountId as fromAccountId8_8_0_,
event1_3_.fromText as fromText3_8_0_,
event1_3_.isProcessed as isProcessed4_8_0_,
event1_3_.replacementEventId as replacementEventId9_8_0_,
event1_3_.toAccountId as toAccountId10_8_0_,
event1_3_.toText as toText5_8_0_,
event1_3_.transactionId as transactionId11_8_0_,
case
when event1_1_.eventId is not null then 1
when event1_2_.eventId is not null then 2
when event1_3_.eventId is not null then 3
when event1_.eventId is not null then 0
end as clazz_0_,
account2_.accountId as accountId1_0_1_,
account2_.context as context2_0_1_,
account2_.currency as currency3_0_1_,
account2_.description as description4_0_1_,
account2_.name as name5_0_1_,
account2_.ownerId as ownerId6_0_1_,
transferev3_.eventId as eventId1_5_2_,
transferev3_1_.baseEventId as baseEventId6_5_2_,
transferev3_1_.eventType as eventType2_5_2_,
transferev3_1_.origin as origin3_5_2_,
transferev3_1_.whenNoticed as whenNoticed4_5_2_,
transferev3_1_.whenOccurred as whenOccurred5_5_2_,
transferev3_.adjustedEventId as adjustedEventId7_8_2_,
transferev3_.amount as amount1_8_2_,
transferev3_.currency as currency2_8_2_,
transferev3_.fromAccountId as fromAccountId8_8_2_,
transferev3_.fromText as fromText3_8_2_,
transferev3_.isProcessed as isProcessed4_8_2_,
transferev3_.replacementEventId as replacementEventId9_8_2_,
transferev3_.toAccountId as toAccountId10_8_2_,
transferev3_.toText as toText5_8_2_,
transferev3_.transactionId as transactionId11_8_2_
from
AUKTIONSMANAGER.tblaccountingentry entries0_
inner join
AUKTIONSMANAGER.tblaccountingevent event1_
on entries0_.eventId=event1_.eventId
left outer join
AUKTIONSMANAGER.tblaccountingapplytempltevent event1_1_
on event1_.eventId=event1_1_.eventId
left outer join
AUKTIONSMANAGER.tblaccountingdeleteentryevent event1_2_
on event1_.eventId=event1_2_.eventId
left outer join
AUKTIONSMANAGER.tblaccountingtransferevent event1_3_
on event1_.eventId=event1_3_.eventId
left outer join
AUKTIONSMANAGER.tblaccountingaccount account2_
on event1_1_.toAccountId=account2_.accountId
left outer join
AUKTIONSMANAGER.tblaccountingtransferevent transferev3_
on event1_2_.adjustedEventId=transferev3_.eventId
left outer join
AUKTIONSMANAGER.tblaccountingevent transferev3_1_
on transferev3_.eventId=transferev3_1_.eventId
where
(
entries0_.deleted = 0
)
and entries0_.accountId=?
Hibernate: -- Hibernate batch - Yes, this takes a looong time.
/* load com.autorola.fleetmonitor.accounting.domain.model.account.Account */ select
account0_.accountId as accountId1_0_0_,
account0_.context as context2_0_0_,
account0_.currency as currency3_0_0_,
account0_.description as description4_0_0_,
account0_.name as name5_0_0_,
account0_.ownerId as ownerId6_0_0_
from
AUKTIONSMANAGER.tblaccountingaccount account0_
where
account0_.accountId in (
?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?
)
2017-03-12 21:29:36,699 INFO [http-bio-24080-exec-10] [org.hibernate.engine.internal.StatisticalLoggingSessionEventListener] Session Metrics {
53910 nanoseconds spent acquiring 1 JDBC connections;
0 nanoseconds spent releasing 0 JDBC connections;
591809 nanoseconds spent preparing 3 JDBC statements;
19238488744 nanoseconds spent executing 3 JDBC statements;
0 nanoseconds spent executing 0 JDBC batches;
0 nanoseconds spent performing 0 L2C puts;
0 nanoseconds spent performing 0 L2C hits;
0 nanoseconds spent performing 0 L2C misses;
0 nanoseconds spent executing 0 flushes (flushing a total of 0 entities and 0 collections);
4819 nanoseconds spent executing 1 partial-flushes (flushing a total of 0 entities and 0 collections)
}
Looking at the system with a profiler - it looks like a lot of network activity - or waiting - which indicates to me that batch-size is ignored.
oracle.net.ns.Packet.receive() 23.024458 19197 ms (23%) 19197 ms
I mean, I can certainly write custom SQL, and tweak annotations for days on end, but Hibernate quickly loses its eligibility when I constantly have to do workarounds and write custom SQL - even if it is in HQL syntax which have learning curve too when you are used to writing and thinking SQL and database models.