Oracle FAQ Your Portal to the Oracle Knowledge Grid
HOME | ASK QUESTION | ADD INFO | SEARCH | E-MAIL US
 

Home -> Community -> Mailing Lists -> Oracle-L -> RE: sql tuning quandry

RE: sql tuning quandry

From: Steve McClure <smcclure_at_usscript.com>
Date: Mon, 12 May 2003 15:12:26 -0800
Message-ID: <F001.0059745A.20030512151226@fatcity.com>


OK First thanks for all the suggestions. Rather than respond to each individually I figure I will just continue the thread in a single response.

In regards to using literals in my sqlplus example and not bind variables. I actually did test it both with and without bind variables. I have done so again and have added the tkprof output from that test with bind variables below. The results were the same, 7 physical reads. The explain plan is identical to the previous examples.

A few of you noted that my tkprof output didn't have values for the rows column. I have been unable to correct this issue. I am making sure the tracing is completed before analyzing the trace file. I have scripts that alter session to start and stop 10046 tracing. What I found is that if I look at the tkprof output of cursor executed at the sqlplus prompt, I get an explain plan with the rows column populated. If I call this cursor from within a function, tkprof lists a plan with 0s in the row column.

OK that said I was able to make a breakthrough of sorts. Using aliases to refer back from the sub query, as one of you suggested. I discovered that the query only caused 80 some fetches. Executing the rewritten using aliases to refer from sub query) query results in 8 reads. I am still confused as to what would be causing this, but am reasonably happy to see some progress in the right direction.

Any clues as to what to look into next? I have included tkprof output from the session where I used bind variables in sqlplus as well as the tkprof of a session where I called the rewritten function. Sorry if this is too much info Jared. It amounts to about 400 lines. Please don't quote me when you respond.



TKPROF from sqlplus session using bind variables

TKPROF: Release 8.1.7.3.0 - Production on Mon May 12 14:57:42 2003

(c) Copyright 2000 Oracle Corporation. All rights reserved.

Trace file: demo_ora_6632.trc
Sort options: default



count    = number of times OCI procedure was executed
cpu      = cpu time in seconds executing
elapsed  = elapsed time in seconds executing
disk     = number of physical reads of buffers from disk
query    = number of buffers gotten for consistent read
current  = number of buffers gotten in current mode (usually for update)
rows     = number of rows processed by the fetch or execute call
****************************************************************************

alter session set events '10046 trace name context forever, level 8'

call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ------



Parse 0 0.00 0.00 0 0 0 0
Execute 1 0.00 0.02 0 0 0 0
Fetch 0 0.00 0.00 0 0 0 0
------- ------ -------- ---------- ---------- ---------- ---------- ------


total 1 0.00 0.02 0 0 0 0

Misses in library cache during parse: 0
Optimizer goal: CHOOSE
Parsing user id: 46 (STEVE)



BEGIN DBMS_APPLICATION_INFO.SET_MODULE(:1,NULL); END; call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ------



Parse 4 0.00 0.00 0 0 0 0
Execute 4 0.00 0.00 0 0 0 4
Fetch 0 0.00 0.00 0 0 0 0
------- ------ -------- ---------- ---------- ---------- ---------- ------


total 8 0.00 0.00 0 0 0 4

Misses in library cache during parse: 0
Optimizer goal: CHOOSE
Parsing user id: 46 (STEVE)



BEGIN :ndc_in_a :='00013103691'; END;

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 1
Fetch 0 0.00 0.00 0 0 0 0
------- ------ -------- ---------- ---------- ---------- ---------- ------


total 2 0.00 0.00 0 0 0 1

Misses in library cache during parse: 0
Optimizer goal: CHOOSE
Parsing user id: 46 (STEVE)



BEGIN DBMS_OUTPUT.GET_LINES(:LINES, :NUMLINES); END; call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ------



Parse 2 0.00 0.00 0 0 0 0
Execute 2 0.00 0.00 0 0 0 2
Fetch 0 0.00 0.00 0 0 0 0
------- ------ -------- ---------- ---------- ---------- ---------- ------


total 4 0.00 0.00 0 0 0 2

Misses in library cache during parse: 0
Optimizer goal: CHOOSE
Parsing user id: 46 (STEVE)



BEGIN :list_id_a:=1; END;

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 1
Fetch 0 0.00 0.00 0 0 0 0
------- ------ -------- ---------- ---------- ---------- ---------- ------


total 2 0.00 0.00 0 0 0 1

Misses in library cache during parse: 0
Optimizer goal: CHOOSE
Parsing user id: 46 (STEVE)



select dp.unit_price
from pbm_drug_price dp
where dp.drug_ndc=:ndc_in_a and dp.prclist_id=:list_id_a and dp.effective_begin=(select max(effective_begin) from pbm_drug_price
where drug_ndc=dp.drug_ndc
and prclist_id=dp.prclist_id)

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 2 0.00 0.00 0 8 0 1
------- ------ -------- ---------- ---------- ---------- ---------- ------


total 4 0.00 0.00 0 8 0 1

Misses in library cache during parse: 1
Optimizer goal: CHOOSE
Parsing user id: 46 (STEVE)

Rows Row Source Operation
------- ---------------------------------------------------

      1  TABLE ACCESS BY INDEX ROWID PBM_DRUG_PRICE
      2   INDEX RANGE SCAN (object id 3264)
      2    SORT AGGREGATE
      1     FIRST ROW
      1      INDEX RANGE SCAN (MIN/MAX) (object id 3264)


Rows     Execution Plan

------- ---------------------------------------------------
0 SELECT STATEMENT GOAL: CHOOSE 1 TABLE ACCESS GOAL: ANALYZED (BY INDEX ROWID) OF 'PBM_DRUG_PRICE' 2 INDEX GOAL: ANALYZED (RANGE SCAN) OF 'DRGPRC_UK' (UNIQUE) 2 SORT (AGGREGATE) 1 FIRST ROW 1 INDEX GOAL: ANALYZED (RANGE SCAN (MIN/MAX)) OF 'DRGPRC_UK' (UNIQUE) ****************************************************************************

alter session set events '10046 trace name context off'

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 0 0.00 0.00 0 0 0 0
------- ------ -------- ---------- ---------- ---------- ---------- ------


total 2 0.00 0.00 0 0 0 0

Misses in library cache during parse: 0
Optimizer goal: CHOOSE
Parsing user id: 46 (STEVE)



OVERALL TOTALS FOR ALL NON-RECURSIVE STATEMENTS call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ------



Parse 10 0.00 0.00 0 0 0 0
Execute 11 0.00 0.02 0 0 0 8
Fetch 2 0.00 0.00 0 8 0 1
------- ------ -------- ---------- ---------- ---------- ---------- ------


total 23 0.00 0.02 0 8 0 9

Misses in library cache during parse: 1

OVERALL TOTALS FOR ALL RECURSIVE STATEMENTS call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ------



Parse 0 0.00 0.00 0 0 0 0
Execute 0 0.00 0.00 0 0 0 0
Fetch 0 0.00 0.00 0 0 0 0
------- ------ -------- ---------- ---------- ---------- ---------- ------


total 0 0.00 0.00 0 0 0 0

Misses in library cache during parse: 0

   11 user SQL statements in session.
    0 internal SQL statements in session.    11 SQL statements in session.
    1 statement EXPLAINed in this session.




Trace file: demo_ora_6632.trc
Trace file compatibility: 8.00.04
Sort options: default
       1  session in tracefile.
      11  user  SQL statements in trace file.
       0  internal SQL statements in trace file.
      11  SQL statements in trace file.
       7  unique SQL statements in trace file.
       1  SQL statements EXPLAINed using schema:
           STEVE.prof$plan_table
             Default table was used.
             Table was created.
             Table was dropped.
     146  lines in trace file.

*******************************************************
END OF FIRST TKPROF


TKPROF of rewritten function call

TKPROF: Release 8.1.7.3.0 - Production on Mon May 12 14:51:53 2003

(c) Copyright 2000 Oracle Corporation. All rights reserved.

Trace file: demo_ora_6577.trc
Sort options: default



count    = number of times OCI procedure was executed
cpu      = cpu time in seconds executing
elapsed  = elapsed time in seconds executing
disk     = number of physical reads of buffers from disk
query    = number of buffers gotten for consistent read
current  = number of buffers gotten in current mode (usually for update)
rows     = number of rows processed by the fetch or execute call
****************************************************************************

alter session set events '10046 trace name context forever, level 8'

call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ------



Parse 0 0.00 0.00 0 0 0 0
Execute 1 0.00 0.00 0 0 0 0
Fetch 0 0.00 0.00 0 0 0 0
------- ------ -------- ---------- ---------- ---------- ---------- ------


total 1 0.00 0.00 0 0 0 0

Misses in library cache during parse: 0
Optimizer goal: CHOOSE
Parsing user id: 46 (STEVE)



BEGIN DBMS_APPLICATION_INFO.SET_MODULE(:1,NULL); END; call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ------



Parse 2 0.00 0.00 0 0 0 0
Execute 2 0.00 0.00 0 0 0 2
Fetch 0 0.00 0.00 0 0 0 0
------- ------ -------- ---------- ---------- ---------- ---------- ------


total 4 0.00 0.00 0 0 0 2

Misses in library cache during parse: 0
Optimizer goal: CHOOSE
Parsing user id: 46 (STEVE)



select pbmadm.common.getdrugprice(1,'00013103691') from
 dual

call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ------



Parse 1 0.01 0.01 0 0 0 0
Execute 1 0.00 0.00 0 0 0 0
Fetch 2 0.00 0.00 0 1 4 1
------- ------ -------- ---------- ---------- ---------- ---------- ------


total 4 0.01 0.01 0 1 4 1

Misses in library cache during parse: 0
Optimizer goal: CHOOSE
Parsing user id: 46 (STEVE)

Rows Row Source Operation
------- ---------------------------------------------------

      1 TABLE ACCESS FULL DUAL Rows Execution Plan
------- ---------------------------------------------------

      0  SELECT STATEMENT   GOAL: CHOOSE
      1   TABLE ACCESS (FULL) OF 'DUAL'

****************************************************************************

SELECT UNIT_PRICE
FROM
 PBM_DRUG_PRICE P WHERE DRUG_NDC = :b1 AND PRCLIST_ID + 0 = :b2 AND   EFFECTIVE_BEGIN = (SELECT MAX(EFFECTIVE_BEGIN) FROM PBM_DRUG_PRICE   WHERE DRUG_NDC = P.DRUG_NDC AND PRCLIST_ID + 0 = P.PRCLIST_ID ) 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 0.02 0.02 85 89 4 1
------- ------ -------- ---------- ---------- ---------- ---------- ------


total 3 0.02 0.02 85 89 4 1

Misses in library cache during parse: 0
Optimizer goal: CHOOSE
Parsing user id: 20 (PBMADM) (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 (RANGE SCAN) OF 'DRGPRC_UK' (UNIQUE)
      0     SORT (AGGREGATE)
      0      INDEX   GOAL: ANALYZED (RANGE SCAN) OF 'DRGPRC_UK' (UNIQUE)


****************************************************************************

alter session set events '10046 trace name context off'

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 0 0.00 0.00 0 0 0 0
------- ------ -------- ---------- ---------- ---------- ---------- ------


total 2 0.00 0.00 0 0 0 0

Misses in library cache during parse: 0
Optimizer goal: CHOOSE
Parsing user id: 46 (STEVE)



OVERALL TOTALS FOR ALL NON-RECURSIVE STATEMENTS call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ------



Parse 4 0.01 0.01 0 0 0 0
Execute 5 0.00 0.00 0 0 0 2
Fetch 2 0.00 0.00 0 1 4 1
------- ------ -------- ---------- ---------- ---------- ---------- ------


total 11 0.01 0.01 0 1 4 3

Misses in library cache during parse: 0

OVERALL TOTALS FOR ALL RECURSIVE STATEMENTS 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 0.02 0.02 85 89 4 1
------- ------ -------- ---------- ---------- ---------- ---------- ------


total 3 0.02 0.02 85 89 4 1

Misses in library cache during parse: 0

    6 user SQL statements in session.
    0 internal SQL statements in session.     6 SQL statements in session.
    2 statements EXPLAINed in this session.




Trace file: demo_ora_6577.trc
Trace file compatibility: 8.00.04
Sort options: default
       1  session in tracefile.
       6  user  SQL statements in trace file.
       0  internal SQL statements in trace file.
       6  SQL statements in trace file.
       5  unique SQL statements in trace file.
       2  SQL statements EXPLAINed using schema:
           STEVE.prof$plan_table
             Default table was used.
             Table was created.
             Table was dropped.
      93  lines in trace file.

**************************

END of tkprof
-- 
Please see the official ORACLE-L FAQ: http://www.orafaq.net
-- 
Author: Steve McClure
  INET: smcclure_at_usscript.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).
Received on Mon May 12 2003 - 18:12:26 CDT

Original text of this message

HOME | ASK QUESTION | ADD INFO | SEARCH | E-MAIL US