| 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 -> Re: PreparedStatement Performance
On Feb 27, 9:40 am, "John.Plan..._at_googlemail.com"
<John.Plan..._at_googlemail.com> wrote:
> 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
> ---------------------------------------- Waited ----------
> ------------
> SQL*Net message to client 316
> 0.00 0.00
> SQL*Net message from client 316
> 0.03 0.16
>
> 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
> ---------------------------------------- Waited ----------
> ------------
> SQL*Net message to client 316
> 0.00 0.00
> SQL*Net message from client 316
> 0.03 0.16
> db file sequential read 33719 0.15
> 222.16
>
> If anyone can shed any light onto this anomoly then I would be most
> grateful.
Considering that the largest wait event during the slow run is db file sequential read, at 3.7 minutes, I would say that on one run the index blocks for PRDS_IDX5 and PRJS_IDI were mostly already in the buffer cache on the fast run, and were mostly not in the buffer cache. Also, keep in mind that explain plans can lie when bind variables are involved.
Assuming that PRDS.ID is a primary key, how does the performance of this SQL statement compare with your SQL statement? SELECT DISTINCT
PD.ID, PD.CODE, PD.STARTSAT, PD.ENDSWITH, PD.REF
 |
 |