| Oracle FAQ | Your Portal to the Oracle Knowledge Grid | |
 |
 | |||
| Oracle FAQ | Your Portal to the Oracle Knowledge Grid | |
|
| |||
Home -> Community -> Usenet -> c.d.o.server -> PreparedStatement Performance
I am using Oracle 10g (10.2.0.1) on Windows (XP SP2). Within my java
code I make extensive use of PreparedStatements (as recommended by
just about everyone). I am experiencing odd performance whereby a
query will sometimes run in around 100 ms and sometimes it takes in
excess of 3 minutes. In both cases the query is exactly the same, the
data is exactly the same and there is no additional load on the
database (this is all running on my desktop machine).
I have tried explain plan, which reports a reasonable execution plan that seems to make use of indexes as expected. Whenever I try to run this query from a sql client (e.g. SQLPLUS), it always returns quickly. I only experience the problem when running the query from a Java JDBC call making use of a PreparedStatment. Perplexed by this, I changed the code and rewrote it to use a Statement instead, so that Oracle has to reparse and recalculate the execution plan every time it is called. Under these circumstances, the query always runs fast (I never see the 3 minutes plus timing). I have tried using both the thin and oci drivers with the same results.
This change to use Statement rather than PreparedStatement would on the face of it seem to solve the problem, but it is not recommended practice and I would rather find out why the problem is occuring and fix it properly.
I get the feeling that Oracle is creating a bad execution plan. When the slow query runs, there is a lot of IO and Statspack and TKPROF both report a large number of reads occuring. If I flush the shared_pool and run the query again, it invariably ends up running quickly again.
The following is the output from TKPROF for the query when it runs quickly
SELECT id,code,startsat,endswith,ref
FROM
PRDS WHERE startsat>= :1 AND ord = -1 AND id IN (SELECT id FROM
PRJS WHERE proj = :2) ORDER BY id,code
call count cpu elapsed disk query current rows
Parse 1 0.00 0.00 0 0 0 0 Execute 1 0.01 0.01 0 0 0 0 Fetch 315 0.04 0.04 0 2319 0 3144
total 317 0.06 0.05 0 2319 0 3144
Misses in library cache during parse: 1
Misses in library cache during execute: 1
Optimizer mode: ALL_ROWS
Parsing user id: 124 (TEST)
Rows Execution Plan
------- ---------------------------------------------------
0 SELECT STATEMENT MODE: ALL_ROWS
0 SORT (ORDER BY)
0 MERGE JOIN
0 TABLE ACCESS MODE: ANALYZED (BY INDEX ROWID) OF
'PRDS' (TABLE)
0 INDEX MODE: ANALYZED (FULL SCAN) OF
'PRDS_IDX5' (INDEX)
0 SORT (JOIN)
0 TABLE ACCESS MODE: ANALYZED (BY INDEX ROWID) OF
'PRJS' (TABLE)
0 INDEX MODE: ANALYZED (RANGE SCAN) OF 'PRJS_IDI'
(INDEX)
Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total
Waited
and this is the output from TKPROF when running the same query (with the same bind variable values) but it running slowly
SELECT id,code,startsat,endswith,ref
FROM
PRDS WHERE startsat>= :1 AND ord = -1 AND id IN (SELECT id FROM
PRJS WHERE proj = :2) ORDER BY id,code
call count cpu elapsed disk query current rows
Parse 1 0.03 0.01 0 12 0 0 Execute 1 0.00 0.00 0 0 0 0 Fetch 315 7.70 229.62 33719 41130 0 3144
total 317 7.73 229.64 33719 41142 0 3144
Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: 124 (TEST)
Rows Execution Plan
------- ---------------------------------------------------
0 SELECT STATEMENT MODE: ALL_ROWS
0 SORT (ORDER BY)
0 MERGE JOIN
0 TABLE ACCESS MODE: ANALYZED (BY INDEX ROWID) OF
'PRDS' (TABLE)
0 INDEX MODE: ANALYZED (FULL SCAN) OF
'PRDS_IDX5' (INDEX)
0 SORT (JOIN)
0 TABLE ACCESS MODE: ANALYZED (BY INDEX ROWID) OF
'PRJS' (TABLE)
0 INDEX MODE: ANALYZED (RANGE SCAN) OF 'PRJS_IDI'
(INDEX)
Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total
Waited
If anyone can shed any light onto this anomoly then I would be most grateful. Received on Tue Feb 27 2007 - 08:40:58 CST
 |
 |