Re: sql tuning quandry

Stephane,

Excellent catch on the TKPROF "explain plan"! You noticed that the explain plan in the TKPROF output displays all-zero values in the "Rows" columns at each step. That is indicative of TKPROF having to run its own EXPLAIN PLAN command. If there had been non-zero values there, then you could be sure that the EXPLAIN PLAN displayed by TKPROF came from "STAT" (a.k.a. Statistics) lines displayed to the ".trc" file when the cursor closed (often when the session disconnects).

I've been re-reading the "Apollo 13" story by Jim Lovell, and to use the parlance mentioned in that book, you are a "steely-eyed missile man" for catching that detail!

Steve,

The TKPROF program has gotten a little smarter lately (i.e. since Oracle7). When you specify the "EXPLAIN=<username>/<password>" parameter on the TKPROF command-line, TKPROF uses it as an indicator that you want EXPLAIN PLAN output included in your report. If TKPROF finds the "STAT" lines in the trace file, it uses that information, which almost always includes non-zero values for "Rows". If TKPROF does not find "STAT" lines for a cursor, then it runs EXPLAIN PLAN using the "username/password" information provided.

To get the more accurate "STAT" lines in your trace, just make sure to end tracing explicitly (i.e. Alter session set sql_trace = false) or end the session normally (i.e. SQL*Plus disconnect or exit)...

---

Another point:  when you ran the query from SQL*Plus, you used literal data
values instead of the bind variables used inside PL/SQL.  Try using the
VARIABLE command in SQL*Plus to use bind variables and see what you get, as
follows:

    set echo on feedback on timing on autotrace on
    variable b1a varchar2(30)
    variable b1b varchar2(30)
    variable b2a number
    variable b2b number
    exec :b1a := '00013103691';
    exec :b1b := '00013103691';
    exec :b2a := 1;
    exec :b2b := 1;

    SELECT UNIT_PRICE
    FROM
    PBM_DRUG_PRICE  WHERE DRUG_NDC = :b1a  AND PRCLIST_ID = :b2b  AND
    EFFECTIVE_BEGIN =  (SELECT MAX(EFFECTIVE_BEGIN)   FROM PBM_DRUG_PRICE
    WHERE DRUG_NDC = :b1b  AND PRCLIST_ID = :b2b )

One of the quirks of SQL*Plus variables is that they can only be used once
within a SQL statement, so instead of just declaring a single "b1" and "b2"
variable, I had to declare two copies of each...

My expectation is that you would see the performance in SQL*Plus now match
what you had in PL/SQL, indicating that the CBO was using histograms on one
(or more) of the columns, something it cannot do with bind variables...

Hope this helps...

-Tim


on 5/10/03 2:17 AM, Stephane Faroult at sfaroult_at_oriole.com wrote:

> Steve McClure wrote:


>> 

>> I have a strange tuning issue, that I have not been able to resolve.  Since

>> this is the first time I have had to progress further down the statement

>> tuning road than 'explain plan', I am not even sure what to look at next.

>>   The situation is this.  We are trying to query the most current price for

>> an item(drug in our business).  The query we typically use is fairly

>> straight forward, and performs well when run directly.  The sql and some

>> autotrace output is included below.  The statement performs well.  All is

>> well..then we needed to place this query in a function to be executed by

>> Discoverer users, and performace hit bottom.  The Tkprof output from that

>> session is below.  I will continue my question on down below that info.

>> 

>> ********************************************************************

>> autotrace output for query run in sqlplus

>> *********************************************************************

>> SELECT UNIT_PRICE

>> FROM

>>  PBM_DRUG_PRICE  WHERE DRUG_NDC ='00013103691'  AND PRCLIST_ID = 1  AND

>>         EFFECTIVE_BEGIN =  (SELECT MAX(EFFECTIVE_BEGIN)   FROM PBM_DRUG_PRICE

>>           WHERE DRUG_NDC = '00013103691'  AND PRCLIST_ID = 1 )

>> 

>> 1 row selected.

>> 

>> Execution Plan

>> ----------------------------------------------------------

>>    0      SELECT STATEMENT Optimizer=CHOOSE (Cost=3 Card=1 Bytes=24)

>>    1    0   TABLE ACCESS (BY INDEX ROWID) OF 'PBM_DRUG_PRICE' (Cost=3

>>           Card=1 Bytes=24)

>> 

>>    2    1     INDEX (UNIQUE SCAN) OF 'DRGPRC_UK' (UNIQUE) (Cost=2 Card

>>           =1)

>> 

>>    3    2       SORT (AGGREGATE)

>>    4    3         FIRST ROW (Cost=3 Card=1 Bytes=20)

>>    5    4           INDEX (RANGE SCAN (MIN/MAX)) OF 'DRGPRC_UK' (UNIQU

>>           E) (Cost=3 Card=1)

>> 

>> Statistics

>> ----------------------------------------------------------

>>           0  recursive calls

>>           0  db block gets

>>           7  consistent gets

>>           0  physical reads

>>           0  redo size

>>         297  bytes sent via SQL*Net to client

>>         358  bytes received via SQL*Net from client

>>           2  SQL*Net roundtrips to/from client

>>           0  sorts (memory)

>>           0  sorts (disk)

>>           1  rows processed

>> 

>> DEMO-frodo-STEVE>spool off

>> 

>> **********************************

>> End of output

>> ***********************************

>> 

>> ****************************************************************************

>> ****

>> tkprof of session executing select

>> pbmadm.common.getdrugprice(1,'00013103691')

>> from dual

>> ****************************************************************************

>> ****

>> 

>> SELECT UNIT_PRICE

>> FROM

>>  PBM_DRUG_PRICE  WHERE DRUG_NDC = :b1  AND PRCLIST_ID = :b2  AND

>>   EFFECTIVE_BEGIN =  (SELECT MAX(EFFECTIVE_BEGIN)   FROM PBM_DRUG_PRICE

>>   WHERE DRUG_NDC = :b1  AND PRCLIST_ID = :b2 )

>> 

>> call     count       cpu    elapsed       disk      query    current

>> rows

>> ------- ------  -------- ---------- ---------- ---------- ----------  ------

>> ----

>> Parse        1      0.00       0.00          0          0          0

>> 0

>> Execute      1      0.00       0.00          0          0          0

>> 0

>> Fetch        1      1.73       2.12       4223       4227         58

>> 1

>> ------- ------  -------- ---------- ---------- ---------- ----------  ------

>> ----

>> total        3      1.73       2.12       4223       4227         58

>> 1

>> 

>> Misses in library cache during parse: 1

>> Optimizer goal: CHOOSE

>> Parsing user id: 20  (USERNAME)   (recursive depth: 1)

>> 

>> Rows     Execution Plan

>> -------  ---------------------------------------------------

>>       0  SELECT STATEMENT   GOAL: CHOOSE

>>       0   TABLE ACCESS   GOAL: ANALYZED (BY INDEX ROWID) OF

>>               'PBM_DRUG_PRICE'

>>       0    INDEX   GOAL: ANALYZED (UNIQUE SCAN) OF 'DRGPRC_UK' (UNIQUE)

>>       0     SORT (AGGREGATE)

>>       0      FIRST ROW

>>       0       INDEX   GOAL: ANALYZED (RANGE SCAN (MIN/MAX)) OF

>>                   'DRGPRC_UK' (UNIQUE)

>> 

>> ****************************************************************************

>> ****

>> 

>> The explain plans are identical.  The performance issue is with the fetches

>> and physical reads.  Executing the query at sqlplus calls for 7 reads.

>> Calling the function causes some 4200 reads.  I have called the function

>> both within a sql query, and from within a pl/sql anonymous block.  The

>> results are the same...4200 reads.

>> 

>> Any Idea where to look next?

>> 

>> Thanks in advance,

>> Steve McClure

>> 

> 
> 
> Steve,
> 
>  If you have run tkprof as
> 
>      tkprof blahblah  explain=username/password
> 
> beware that the plan is the output of the 'EXPLAIN' command when tkprof
> runs, which is not necessarily the same as the actual one which was
> executed (and for which you get the stats).
> It may be that stats were perhaps out of date or an index missing when
> the trace file was generated.
> Generally speaking, I prefer this kind of query to be written
> 
> SELECT UNIT_PRICE
> FROM
> PBM_DRUG_PRICE  WHERE (DRUG_NDC, PRCLIST_ID, EFFECTIVE_BEGIN) =
> (SELECT DRUG_NDC, PRCLIST_ID, MAX(EFFECTIVE_BEGIN)   FROM
> PBM_DRUG_PRICE
>  WHERE DRUG_NDC = :b1  AND PRCLIST_ID = :b2
>  GROUP BY DRUG_NDC, PRCLIST_ID)
> 
> It shouldn't change much in your case, but it tells Oracle a bit more
> about the way I want it to do it.
> And I am no great fan of queries in functions. Sooner or later you find
> people to use your function in such a way that it's called for each row
> of a mega-table scan. Ouch.

-- 
Please see the official ORACLE-L FAQ: http://www.orafaq.net
-- 
Author: Tim Gorman
  INET: tim_at_sagelogix.com

Fat City Network Services    -- 858-538-5051 http://www.fatcity.com
San Diego, California        -- Mailing list and web hosting services
---------------------------------------------------------------------
To REMOVE yourself from this mailing list, send an E-Mail message
to: ListGuru_at_fatcity.com (note EXACT spelling of 'ListGuru') and in
the message BODY, include a line containing: UNSUB ORACLE-L
(or the name of mailing list you want to be removed from).  You may
also send the HELP command for other information (like subscribing).