I am currently facing a problem with a slow running Hibernate query that is being kicked off from a Java program. It is making a call to Oracle 11g at the back end.
This query is taking anything from 40-90 seconds the first time it is run. On subsequent executions however the query is returned in a fraction of the time (and I don't even see the database being hit, so assume that hibernate is caching it).
If I copy and paste the query from Enterprise Manager into a SQL client and run the very same query directly (even changing a few parameters) the query returns in a fraction of a second.
If I look at the performance tuning tab in EM I see that the time taken is primarily taken up with User I/O Waits (97.5%), and CPU (2.5%). Could this mean that the fetch size I am using in hibernate is configured at too small a value?
If there is any other information you might need to help me get to the bottom of this issue then please let me know.
=====
Additional information:
We do have an index on the table and I can see that it is being used as part of the execution of the query, unfortunately it isn't very readable but I am not sure how else to include it:
Id Operation Name Rows
(Estim) Cost Time
Active(s) Start
Active Execs Rows
(Actual) Read
Reqs Read
Bytes Mem
(Max) Activity
(%) Activity Detail
(# samples)
0 SELECT STATEMENT 1
1 . FILTER 1
2 .. HASH JOIN RIGHT OUTER 2674 7223 1 +4 1 0 1M
3 ... TABLE ACCESS FULL TOTEM_EQ_EXPIRYCODES 475 4 1 +4 1 481
4 ... HASH JOIN RIGHT OUTER 2674 7219 1 +4 1 0 399K
5 .... TABLE ACCESS BY INDEX ROWID TOTEM_EQ_UNDERLYINGS 1 2 1 +4 1 1
6 ..... INDEX UNIQUE SCAN TOTEM_EQ_UND_PK 1 1 1 +4 1 1
7 .... NESTED LOOPS 1
8 ..... NESTED LOOPS 2674 7216 42 +4 1 0
9 ...... TABLE ACCESS BY GLOBAL INDEX ROWID EQUITIES_MONTHLY_INSTRUMENTS 2671 1871 45 +1 1 8438 3517 27MB 24.44 db file sequential read (11)
10 ....... INDEX RANGE SCAN EQ_MON_INS_UNDERLYING_INDX 2671 12 42 +4 1 8438 27 216KB
11 ...... PARTITION RANGE ITERATOR 1 2 8438
12 ....... INDEX RANGE SCAN EQ_MON_RESULT_INSPT_UNQ 1 2 44 +2 8438 0 5403 42MB 75.56 Cpu (1)
db file sequential read (33)
13 ..... TABLE ACCESS BY LOCAL INDEX ROWID EQUITIES_MONTHLY_RESULTS 1 3
Here are the Global stats:
Elapsed
Time(s) Cpu
Time(s) IO
Waits(s) Fetch
Calls Buffer
Gets Read
Reqs Read
Bytes
45 0.73 45 1 22980 9740 76MB
Best Answer
It turns out that the problem was to do with the index that was being selected as part of the query plan.
The query was accepting a range as part of its set of parameters. For reasons I won't go into now we were passing the range start and end date to be the same value.
When we were making the call directly we were hard coding these parameters and Oracle was deducing that they represented a single date, whereas when passing them via code the range was passed as bind variables.
This meant that Oracle selected to scan across all partitions in one case, and against a specific partition in the other.
We ultimately fixed the query by passing in just a single date parameter, since we realised we didn't need a range!
A rather peculiar situation admittedly!