On 27 Feb, 15:28, "joeNOS..._at_BEA.com" <joe.weinst..._at_gmail.com> wrote:
> On Feb 27, 6: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.
>
> Hi. Do you retain and re-use your prepared Statements,
> or do you create, use, and then close them?
> Joe Weinstein at BEA Systems- Hide quoted text -
>
> - Show quoted text -
The PreparedStatement is created and retained
Received on Tue Feb 27 2007 - 10:04:21 CST
