Home » RDBMS Server » Performance Tuning » Why two sets of explain plans in tkprof..ed file??
| Why two sets of explain plans in tkprof..ed file?? [message #141127] |
Fri, 07 October 2005 01:38  |
wushu_kid
Messages: 7
Registered: October 2005
|
Junior Member |
|
|
Why is there two sets of explain plans...
1. Row Source Operation
2. Execution Plan
Misses in library cache during parse: 1
Optimizer goal: CHOOSE
Parsing user id: 21 (OPS$ORACLE)
Rows Row Source Operation
------- ---------------------------------------------------
116037 PARTITION RANGE SINGLE PARTITION: KEY KEY
116037 TABLE ACCESS FULL TB PARTITION: KEY KEY
Rows Execution Plan
------- ---------------------------------------------------
0 SELECT STATEMENT GOAL: CHOOSE
116037 PARTITION RANGE (SINGLE) PARTITION:KEYKEY
116037 INDEX GOAL: ANALYZED (RANGE SCAN) OF 'TB_KEY' (NON-UNIQUE)
PARTITION:KEYKEY
|
|
|
|
|
|
| Re: Why two sets of explain plans in tkprof..ed file?? [message #141190 is a reply to message #141127] |
Fri, 07 October 2005 07:57  |
wushu_kid
Messages: 7
Registered: October 2005
|
Junior Member |
|
|
Thks buddy. There are 2 different explain plans.One is a FTS and the other is using an index. I am using bind variables throughout. This is using trace and tkprof.
With another experiment using autotrace it shows same plan using an index. bind value peeking did not work!
Basically I want the query key=1 to use FTS.. and key = 100 to use the index.
There is many values for 1 but only one value of 100. Got the idea.
Here is the full story....
SQL> drop table TB ;
Table dropped.
SQL> create table tb (
key int,
x int
)
partition by range (key)
(
partition p_oneval values less than (10),
partition p_distinct values less than (99999999)
)
/
Table created.
SQL> insert into tb partition (p_oneval) (key, x)
select 1 , rownum
from all_objects where rownum <= 10000 ;
7733 rows created.
SQL>
SQL> insert into tb partition (p_distinct) (key, x)
select 10+rownum-1, rownum
from all_objects where rownum <= 10000 ;
7733 rows created.
SQL> commit ;
SQL> exec dbms_stats.gather_table_stats ( 'OPS$ORACLE','TB',CASCADE=>TRUE);
PL/SQL procedure successfully completed.
SQL> select partition_name, num_rows from dba_tab_partitions where table_name='TB';
PARTITION_NAME NUM_ROWS
------------------------------ ----------
P_ONEVAL 7733
P_DISTINCT 7733
alter session set sql_trace=true;
variable key number
exec :key := 1; -- hits partition p_oneval
select /* key=1 */ x from tb where key = :key;
Many rows...
See APENDIX A. TKPROF FILE
SQL> exec :key := 100;
PL/SQL procedure successfully completed.
SQL> select /* key=100 */ x from tb where key = :key;
X
----------
91
See APENDIX A. TKPROF FILE
APPENDIX A
TKPROF: Release 9.2.0.6.0 - Production on Thu Oct 6 15:24:08 2005
Copyright (c) 1982, 2002, Oracle Corporation. All rights reserved.
Trace file: b.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 sql_trace=true
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: 21 (OPS$ORACLE)
********************************************************************************
BEGIN :key := 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: 21 (OPS$ORACLE)
********************************************************************************
select /* key=1 */ x
from tb where key = :key
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 517 0.01 0.01 0 532 0 7733
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 519 0.01 0.01 0 532 0 7733
Misses in library cache during parse: 1
Optimizer goal: CHOOSE
Parsing user id: 21 (OPS$ORACLE)
Rows Row Source Operation
------- ---------------------------------------------------
7733 PARTITION RANGE SINGLE PARTITION: KEY KEY
7733 TABLE ACCESS FULL TB PARTITION: KEY KEY
Rows Execution Plan
------- ---------------------------------------------------
0 SELECT STATEMENT GOAL: CHOOSE
7733 PARTITION RANGE (SINGLE) PARTITION:KEYKEY
7733 TABLE ACCESS GOAL: ANALYZED (BY LOCAL INDEX ROWID) OF 'TB'
PARTITION:KEYKEY
0 INDEX GOAL: ANALYZED (RANGE SCAN) OF 'TB_KEY' (NON-UNIQUE)
PARTITION:KEYKEY
********************************************************************************
BEGIN :key := 100; 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: 21 (OPS$ORACLE)
********************************************************************************
select /* key=100 */ x
from tb where key = :key
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 4 0 1
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 4 0.00 0.00 0 4 0 1
Misses in library cache during parse: 1
Optimizer goal: CHOOSE
Parsing user id: 21 (OPS$ORACLE)
Rows Execution Plan
------- ---------------------------------------------------
0 SELECT STATEMENT GOAL: CHOOSE
0 PARTITION RANGE (SINGLE) PARTITION:KEYKEY
0 TABLE ACCESS GOAL: ANALYZED (BY LOCAL INDEX ROWID) OF 'TB'
PARTITION:KEYKEY
0 INDEX GOAL: ANALYZED (RANGE SCAN) OF 'TB_KEY' (NON-UNIQUE)
PARTITION:KEYKEY
********************************************************************************
OVERALL TOTALS FOR ALL NON-RECURSIVE STATEMENTS
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 4 0.00 0.00 0 0 0 0
Execute 5 0.00 0.00 0 0 0 2
Fetch 519 0.01 0.01 0 536 0 7734
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 528 0.01 0.01 0 536 0 7736
Misses in library cache during parse: 2
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
5 user SQL statements in session.
0 internal SQL statements in session.
5 SQL statements in session.
2 statements EXPLAINed in this session.
********************************************************************************
Trace file: b.trc
Trace file compatibility: 9.02.00
Sort options: default
1 session in tracefile.
5 user SQL statements in trace file.
0 internal SQL statements in trace file.
5 SQL statements in trace file.
5 unique SQL statements in trace file.
2 SQL statements EXPLAINed using schema:
OPS$ORACLE.prof$plan_table
Default table was used.
Table was created.
Table was dropped.
570 lines in trace file.
APPENDIX B – autotrace shows both plans are SAME !!!!
7733 rows selected.
Execution Plan
----------------------------------------------------------
0 SELECT STATEMENT Optimizer=CHOOSE (Cost=2 Card=2 Bytes=14)
1 0 PARTITION RANGE (SINGLE)
2 1 TABLE ACCESS (BY LOCAL INDEX ROWID) OF 'TB' (Cost=2 Card
=2 Bytes=14)
3 2 INDEX (RANGE SCAN) OF 'TB_KEY' (NON-UNIQUE) (Cost=1 Ca
rd=2)
SQL> exec :key := 100;
PL/SQL procedure successfully completed.
SQL> select /* key=100 */ x from tb where key = :key;
X
----------
91
Execution Plan
----------------------------------------------------------
0 SELECT STATEMENT Optimizer=CHOOSE (Cost=2 Card=2 Bytes=14)
1 0 PARTITION RANGE (SINGLE)
2 1 TABLE ACCESS (BY LOCAL INDEX ROWID) OF 'TB' (Cost=2 Card
=2 Bytes=14)
3 2 INDEX (RANGE SCAN) OF 'TB_KEY' (NON-UNIQUE) (Cost=1 Ca
rd=2)
|
|
|
|
| Re: Why two sets of explain plans in tkprof..ed file?? [message #141196 is a reply to message #141127] |
Fri, 07 October 2005 08:14 |
smartin
Messages: 1803
Registered: March 2005
Location: Jacksonville, Florida
|
Senior Member |
|
|
1. It is good that you are looking at this stuff and posting it for us to read through and learn from as well. And it is a good test idea.
2. Something looks fishy. You create your table, insert your rows, gather your stats. But at no point do you create any indexes. Yet your autotrace plan shows an index scan?
3. I don't think (not 100% certain, we should be able to test/confirm this) that autotrace ever shows bind variable peeking. But the TKPROF plan is the real plan that was used.
4. Your second plan did use an index, it had way less disk io (like 4 consistent gets I think) in retrieving value for key = 100, which is what you wanted but said didn't happen. The first plan did a FTS (of the partition) as it did like 500 something consistent gets.
5. You should not (in almost all cases) specify the partition name physically when you do an insert statement, the whole point of them is to be transparent to the application and the sql. Just do your insert and let oracle place the values in the appropriate partitions based on the partition key.
6. You never gathered histograms. Always gather histograms. If you haven't gathered histograms, you haven't gather statistics in my mind. How else can oracle know about the data distribution of your values? method_opt for all columns size 250
7. When showing us tkprof output, please don't show us the whole file, and the measurements of alter sessions and setting bind variables. Only show us the 2 relevent queries, lot less info for us to wade through, meaning more likely we will read it.
|
|
|
|
|
|
|
|
| Re: Why two sets of explain plans in tkprof..ed file?? [message #141441 is a reply to message #141127] |
Mon, 10 October 2005 05:29 |
wushu_kid
Messages: 7
Registered: October 2005
|
Junior Member |
|
|
THKS comrades . Hope u had a peaceful weekend. Thks for reading right to the details. Yes the index creation is missing. ;-( It is cut and paste thingo ! Hope this one is clearer and try to incorporate some of you guys suggestions too.
Still getting 2 paragraphs
1. rows source operation
2. explain plan
So which plan did the optimiser actually used?!
I included a autotrace case study as well. It works perfectly as I want it to work. But bind variables did not work for me. This time it is worst. The secound query = 100 also shows the abovementioned 2 paragraphs which confuses me.
SQL> drop table tb ;
Table dropped.
SQL> create table tb (
key int,
x int
)
partition by range (key)
(
partition p_oneval values less than (10),
partition p_distinct values less than (99999999)
);
Table created.
SQL> insert into tb ( key, x ) select 1, rownum
2 from all_objects where rownum <= 10000;
7736 rows created.
SQL> /
7736 rows created.
SQL> /
7736 rows created.
and so on........ until
SQL> select count(*) from tb where key=1 ;
COUNT(*)
----------
69621
SQL> insert into tb partition (p_distinct) (key, x)
select 10+rownum-1, rownum
from all_objects where rownum <= 10000;
7733 rows created.
SQL> select count(*) from tb where key > 1;
COUNT(*)
----------
7733
SQL> select count(*) from tb where key=100 ;
COUNT(*)
----------
1
SQL> select count(*) from tb ;
COUNT(*)
----------
77354
SQL> create index tb_key on tb (key) LOCAL;
Index created.
SQL> exec dbms_stats.gather_table_stats('OPS$ORACLE','TB',CASCADE=>TRUE,METHOD_OPT=>'FOR COLUMNS SIZE 20 KEY' ) ;
PL/SQL procedure successfully completed.
1 SELECT column_name, num_distinct, num_buckets
2 FROM USER_TAB_COL_STATISTICS
3* where table_name='TB' and column_name='KEY'
SQL> /
COLUMN_NAME NUM_DISTINCT NUM_BUCKETS
------------------------------ ------------ -----------
KEY 7734 2
SQL> SELECT endpoint_number, endpoint_value
FROM USER_HISTOGRAMS
WHERE table_name ='TB' and column_name='KEY'
order by endpoint_number ;
ENDPOINT_NUMBER ENDPOINT_VALUE
--------------- --------------
18 1
19 3875
20 7742
CASE 1 LITERAL QUERIES for key = 1 and key = 100
set autotrace on explain statistics
select key from tb where key=1 ;
set autotrace off ;
69621 rows selected.
Execution Plan
----------------------------------------------------------
0 SELECT STATEMENT Optimizer=CHOOSE (Cost=20 Card=69621 Bytes=
208863)
1 0 TABLE ACCESS (FULL) OF 'TB' (Cost=20 Card=69621 Bytes=2088
63)
set autotrace on explain statistics
select key from tb where key=100 ;
set autotrace off ;
KEY
----------
100
Execution Plan
----------------------------------------------------------
0 SELECT STATEMENT Optimizer=CHOOSE (Cost=1 Card=1 Bytes=4)
1 0 INDEX (RANGE SCAN) OF 'TB_KEY' (NON-UNIQUE) (Cost=1 Card=1
Bytes=4)
FANTASTIC !!!!!! <------------- Literal works OK
CASE 2 USE BIND VALUES KEY=1
alter session set events '10046 trace name context forever, level 12' ;
variable key number ;
exec :key :=1 ;
select key from tb where key = :key ;
Trace file: spgd_ora_6750398.trc
********************************************************************************
alter session set events '10046 trace name context forever, level 12'
BEGIN :key :=1 ; END;
select key
from
tb where key = :key
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 4643 0.14 0.12 0 4755 0 69621
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 4645 0.14 0.12 0 4755 0 69621
Misses in library cache during parse: 0
Optimizer goal: CHOOSE
Parsing user id: 21 (OPS$ORACLE)
-------> This part confuses me
Rows Row Source Operation
------- ---------------------------------------------------
69621 PARTITION RANGE SINGLE PARTITION: KEY KEY
69621 TABLE ACCESS FULL OBJ#(12297) PARTITION: KEY KEY
Rows Execution Plan
------- ---------------------------------------------------
0 SELECT STATEMENT GOAL: CHOOSE
69621 PARTITION RANGE (SINGLE) PARTITION:KEYKEY
69621 INDEX GOAL: ANALYZED (RANGE SCAN) OF 'TB_KEY' (NON-UNIQUE)
PARTITION:KEYKEY
---------> why the first one appears to be a FTS and the secound one using tb_key index ???? ;-(
CASE 3 BIND VALUE KEY=100
********************************************************************************
alter session set events '10046 trace name context forever, level 12'
BEGIN :key :=100 ; END;
select key from tb where key = :key
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.01 0.00 0 24 0 1
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 4 0.01 0.00 0 24 0 1
Misses in library cache during parse: 0
Optimizer goal: CHOOSE
Parsing user id: 21 (OPS$ORACLE)
--------> Why FTS here ????????
Rows Row Source Operation
------- ---------------------------------------------------
1 PARTITION RANGE SINGLE PARTITION: KEY KEY
1 TABLE ACCESS FULL OBJ#(12297) PARTITION: KEY KEY
Rows Execution Plan
------- ---------------------------------------------------
0 SELECT STATEMENT GOAL: CHOOSE
1 PARTITION RANGE (SINGLE) PARTITION:KEYKEY
1 INDEX GOAL: ANALYZED (RANGE SCAN) OF 'TB_KEY' (NON-UNIQUE)
PARTITION:KEYKEY
----------> FTS or index ?
----------> This is KUNGFUCING !!!!!
|
|
|
|
| Re: Why two sets of explain plans in tkprof..ed file?? [message #141499 is a reply to message #141127] |
Mon, 10 October 2005 09:49 |
smartin
Messages: 1803
Registered: March 2005
Location: Jacksonville, Florida
|
Senior Member |
|
|
According to pages 460-462 of Expert One On One Oracle, the Row Source Operation is the "real" explain plan. By real I mean the one that was actually executed. If you use the explain= option on the tkprof command line, you are asking oracle to, in addition to the row source operation information that it read from the tracefile (thus was actually used), to also generate a new explain plan now based on current settings and factors.
So, don't use the explain= command line option, or do so carefully.
|
|
|
|
| Re: Why two sets of explain plans in tkprof..ed file?? [message #141508 is a reply to message #141127] |
Mon, 10 October 2005 11:04 |
smartin
Messages: 1803
Registered: March 2005
Location: Jacksonville, Florida
|
Senior Member |
|
|
Ok, I wrote the following test based on your test case. For the below run, it shows the autotrace/explain plans in sqlplus being the same as the row source operation in the trace. I'm on 10.1.0.4 on windows.
Actually I thought on an earlier run of it I saw a different sqlplus autotrace than tkprof trace row source, but maybe not. One thing to experiment with is changing the size of the data column, as that directly impacts the cost of the amount of data read by a FTS.
Anyway, in both the bind and the non bind case, the below does a single partition FTS when key = 1, and an index scan when key = 100.
MYDBA@ORCL >
MYDBA@ORCL > create table test(key number, x char(10))
2 partition by range(key)
3 (
4 partition p1 values less than (10),
5 partition p2 values less than (maxvalue)
6 );
Table created.
MYDBA@ORCL >
MYDBA@ORCL > insert into test select 1, 'p1' from all_objects where rownum <= 10000;
10000 rows created.
MYDBA@ORCL > insert into test select 10+rownum, 'p2' from all_objects where rownum <= 10000;
10000 rows created.
MYDBA@ORCL > commit;
Commit complete.
MYDBA@ORCL >
MYDBA@ORCL > create index test_idx on test(key);
Index created.
MYDBA@ORCL >
MYDBA@ORCL > exec dbms_stats.gather_table_stats(user,'test',cascade=>true,method_opt=>'for all columns size 250');
PL/SQL procedure successfully completed.
MYDBA@ORCL >
MYDBA@ORCL > select column_name, global_stats, num_distinct, num_buckets, histogram
2 from dba_tab_col_statistics where table_name = 'TEST';
COLUMN_NAME GLO NUM_DISTINCT NUM_BUCKETS HISTOGRAM
------------------------------ --- ------------ ----------- ---------------
KEY YES 10001 250 HEIGHT BALANCED
X YES 2 2 FREQUENCY
2 rows selected.
MYDBA@ORCL >
MYDBA@ORCL > select * from
2 (
3 select substr(column_name,1,30) "Column", endpoint_number, endpoint_value
4 from dba_histograms where table_name = 'TEST' order by 1 desc, 2
5 )
6 where rownum < 15;
Column ENDPOINT_NUMBER ENDPOINT_VALUE
------------------------------ --------------- --------------
X 10000 5.8253E+35
X 20000 5.8255E+35
KEY 125 1
KEY 126 90
KEY 127 170
KEY 128 250
KEY 129 330
KEY 130 410
KEY 131 490
KEY 132 570
KEY 133 650
KEY 134 730
KEY 135 810
KEY 136 890
14 rows selected.
MYDBA@ORCL >
MYDBA@ORCL > set autotrace on explain statistics;
MYDBA@ORCL > select count(*) from test where key = 1;
COUNT(*)
----------
10000
1 row selected.
Execution Plan
----------------------------------------------------------
0 SELECT STATEMENT Optimizer=ALL_ROWS (Cost=8 Card=1 Bytes=3)
1 0 SORT (AGGREGATE)
2 1 PARTITION RANGE (SINGLE) (Cost=8 Card=10000 Bytes=30000)
3 2 TABLE ACCESS (FULL) OF 'TEST' (TABLE) (Cost=8 Card=10000 Bytes=30000)
Statistics
----------------------------------------------------------
1 recursive calls
0 db block gets
31 consistent gets
0 physical reads
0 redo size
420 bytes sent via SQL*Net to client
508 bytes received via SQL*Net from client
2 SQL*Net roundtrips to/from client
0 sorts (memory)
0 sorts (disk)
1 rows processed
MYDBA@ORCL > select count(*) from test where key = 100;
COUNT(*)
----------
1
1 row selected.
Execution Plan
----------------------------------------------------------
0 SELECT STATEMENT Optimizer=ALL_ROWS (Cost=1 Card=1 Bytes=4)
1 0 SORT (AGGREGATE)
2 1 INDEX (RANGE SCAN) OF 'TEST_IDX' (INDEX) (Cost=1 Card=1 Bytes=4)
Statistics
----------------------------------------------------------
1 recursive calls
0 db block gets
2 consistent gets
1 physical reads
0 redo size
420 bytes sent via SQL*Net to client
508 bytes received via SQL*Net from client
2 SQL*Net roundtrips to/from client
0 sorts (memory)
0 sorts (disk)
1 rows processed
MYDBA@ORCL > set autotrace off;
MYDBA@ORCL >
MYDBA@ORCL > explain plan for
2 select count(*) from test where key = 1;
Explained.
MYDBA@ORCL > select * from table(dbms_xplan.display);
PLAN_TABLE_OUTPUT
-----------------------------------------------------------------------------------------------
Plan hash value: 4044019124
------------------------------------------------------------------------------------------------
| Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time | Pstart| Pstop
------------------------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 1 | 3 | 8 (0)| 00:00:01 | |
| 1 | SORT AGGREGATE | | 1 | 3 | | | |
| 2 | PARTITION RANGE SINGLE| | 10000 | 30000 | 8 (0)| 00:00:01 | 1 | 1
|* 3 | TABLE ACCESS FULL | TEST | 10000 | 30000 | 8 (0)| 00:00:01 | 1 | 1
-----------------------------------------------------------------------------------------------
Predicate Information (identified by operation id):
---------------------------------------------------
3 - filter("KEY"=1)
15 rows selected.
MYDBA@ORCL >
MYDBA@ORCL > explain plan for
2 select count(*) from test where key = 100;
Explained.
MYDBA@ORCL > select * from table(dbms_xplan.display);
PLAN_TABLE_OUTPUT
-----------------------------------------------------------------------------------------------
Plan hash value: 190015244
------------------------------------------------------------------------------
| Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time |
------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 1 | 4 | 1 (0)| 00:00:01 |
| 1 | SORT AGGREGATE | | 1 | 4 | | |
|* 2 | INDEX RANGE SCAN| TEST_IDX | 1 | 4 | 1 (0)| 00:00:01 |
------------------------------------------------------------------------------
Predicate Information (identified by operation id):
---------------------------------------------------
2 - access("KEY"=100)
14 rows selected.
MYDBA@ORCL >
MYDBA@ORCL > variable mykey1 number;
MYDBA@ORCL > variable mykey100 number;
MYDBA@ORCL > exec :mykey1 := 1;
PL/SQL procedure successfully completed.
MYDBA@ORCL > exec :mykey100 := 100;
PL/SQL procedure successfully completed.
MYDBA@ORCL >
MYDBA@ORCL > set autotrace on explain statistics;
MYDBA@ORCL > select count(*) from test where key = :mykey1;
COUNT(*)
----------
10000
1 row selected.
Execution Plan
----------------------------------------------------------
0 SELECT STATEMENT Optimizer=ALL_ROWS (Cost=1 Card=1 Bytes=4)
1 0 SORT (AGGREGATE)
2 1 INDEX (RANGE SCAN) OF 'TEST_IDX' (INDEX) (Cost=1 Card=2 Bytes=8)
Statistics
----------------------------------------------------------
1 recursive calls
0 db block gets
31 consistent gets
0 physical reads
0 redo size
420 bytes sent via SQL*Net to client
508 bytes received via SQL*Net from client
2 SQL*Net roundtrips to/from client
0 sorts (memory)
0 sorts (disk)
1 rows processed
MYDBA@ORCL > select count(*) from test where key = :mykey100;
COUNT(*)
----------
1
1 row selected.
Execution Plan
----------------------------------------------------------
0 SELECT STATEMENT Optimizer=ALL_ROWS (Cost=1 Card=1 Bytes=4)
1 0 SORT (AGGREGATE)
2 1 INDEX (RANGE SCAN) OF 'TEST_IDX' (INDEX) (Cost=1 Card=2 Bytes=8)
Statistics
----------------------------------------------------------
1 recursive calls
0 db block gets
2 consistent gets
0 physical reads
0 redo size
420 bytes sent via SQL*Net to client
508 bytes received via SQL*Net from client
2 SQL*Net roundtrips to/from client
0 sorts (memory)
0 sorts (disk)
1 rows processed
MYDBA@ORCL > set autotrace off;
MYDBA@ORCL >
MYDBA@ORCL > alter session set events '10046 trace name context forever, level 12';
Session altered.
MYDBA@ORCL > select count(*) from test where key = 1;
COUNT(*)
----------
10000
1 row selected.
MYDBA@ORCL > select count(*) from test where key = 100;
COUNT(*)
----------
1
1 row selected.
MYDBA@ORCL > select count(*) from test where key = :mykey1;
COUNT(*)
----------
10000
1 row selected.
MYDBA@ORCL > select count(*) from test where key = :mykey100;
COUNT(*)
----------
1
1 row selected.
MYDBA@ORCL > alter session set events '10046 trace name context off';
Session altered.
MYDBA@ORCL >
MYDBA@ORCL > select value || '/' || instance_name || '_ora_' || spid || '.trc' filename
2 from v$process, v$session, v$instance, v$parameter
3 where v$parameter.name = 'user_dump_dest'
4 and v$session.paddr = v$process.addr
5 and v$session.audsid = sys_context('userenv','sessionid');
FILENAME
-----------------------------------------------------------------------------------------------
E:\ORACLE\PRODUCT\10.1.0\ADMIN\ORCL\UDUMP/orcl_ora_3616.trc
1 row selected.
MYDBA@ORCL >
MYDBA@ORCL > drop table test;
Table dropped.
MYDBA@ORCL > set echo off;
And here is the relevent portion of the tkprof file
select count(*)
from
test where key = 1
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.01 0.00 0 0 0 0
Execute 1 0.01 0.01 0 0 0 0
Fetch 2 0.01 0.01 0 31 0 1
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 4 0.03 0.02 0 31 0 1
Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: 64
Rows Row Source Operation
------- ---------------------------------------------------
1 SORT AGGREGATE (cr=31 pr=0 pw=0 time=10317 us)
10000 PARTITION RANGE SINGLE PARTITION: 1 1 (cr=31 pr=0 pw=0 time=70302 us)
10000 TABLE ACCESS FULL TEST PARTITION: 1 1 (cr=31 pr=0 pw=0 time=30261 us)
Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total Waited
---------------------------------------- Waited ---------- ------------
SQL*Net message to client 2 0.00 0.00
SQL*Net message from client 2 0.00 0.00
********************************************************************************
select count(*)
from
test where key = 100
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 2 0 1
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 4 0.00 0.00 0 2 0 1
Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: 64
Rows Row Source Operation
------- ---------------------------------------------------
1 SORT AGGREGATE (cr=2 pr=0 pw=0 time=265 us)
1 INDEX RANGE SCAN TEST_IDX (cr=2 pr=0 pw=0 time=171 us)(object id 80317)
Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total Waited
---------------------------------------- Waited ---------- ------------
SQL*Net message to client 2 0.00 0.00
SQL*Net message from client 2 0.00 0.00
********************************************************************************
select count(*)
from
test where key = :mykey1
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.01 0.00 0 0 0 0
Execute 1 0.03 0.03 0 0 0 0
Fetch 2 0.01 0.01 0 31 0 1
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 4 0.05 0.05 0 31 0 1
Misses in library cache during parse: 1
Misses in library cache during execute: 1
Optimizer mode: ALL_ROWS
Parsing user id: 64
Rows Row Source Operation
------- ---------------------------------------------------
1 SORT AGGREGATE (cr=31 pr=0 pw=0 time=10939 us)
10000 PARTITION RANGE SINGLE PARTITION: KEY KEY (cr=31 pr=0 pw=0 time=80341 us)
10000 TABLE ACCESS FULL TEST PARTITION: KEY KEY (cr=31 pr=0 pw=0 time=30274 us)
Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total Waited
---------------------------------------- Waited ---------- ------------
SQL*Net message to client 2 0.00 0.00
SQL*Net message from client 2 0.01 0.01
********************************************************************************
select count(*)
from
test where key = :mykey100
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.01 0.00 0 0 0 0
Execute 1 0.02 0.02 0 0 0 0
Fetch 2 0.00 0.00 0 2 0 1
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 4 0.03 0.03 0 2 0 1
Misses in library cache during parse: 1
Misses in library cache during execute: 1
Optimizer mode: ALL_ROWS
Parsing user id: 64
Rows Row Source Operation
------- ---------------------------------------------------
1 SORT AGGREGATE (cr=2 pr=0 pw=0 time=268 us)
1 INDEX RANGE SCAN TEST_IDX (cr=2 pr=0 pw=0 time=173 us)(object id 80317)
Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total Waited
---------------------------------------- Waited ---------- ------------
SQL*Net message to client 2 0.00 0.00
SQL*Net message from client 2 0.00 0.00
********************************************************************************
If on another run anything does differ, remember that you can also look at the consistent gets to get a clue as to whether a FTS or index scan was performed. Index scan will only need to read a couple of blocks, so if the plan says FTS but the gets were only 2 then you know it really did an index scan.
|
|
|
|
| Re: Why two sets of explain plans in tkprof..ed file?? [message #141726 is a reply to message #141127] |
Tue, 11 October 2005 17:48 |
wushu_kid
Messages: 7
Registered: October 2005
|
Junior Member |
|
|
Thanks smartin for the very informative reply.
yep I added the explain=/ in tkprof command. Now I have a single entry for explain plan and it is the correct result.
However ;-( !!!! You ndid otice it correctly as before. BIND values did not give me the correct result it uses the index for both key= :v1 and key = :v100 ( i.e. key=1 , key=100 )respectively.
This is what I get for
select * from tb where key = :v1
1 7735
1 7736
results shorten......here
69621 rows selected.
Execution Plan
----------------------------------------------------------
0 SELECT STATEMENT Optimizer=CHOOSE (Cost=2 Card=10 Bytes=70)
1 0 PARTITION RANGE (SINGLE)
2 1 TABLE ACCESS (BY LOCAL INDEX ROWID) OF 'TB' (Cost=2 Card
=10 Bytes=70)
3 2 INDEX (RANGE SCAN) OF 'TB_KEY' (NON-UNIQUE) (Cost=1 Ca
rd=10)
Statistics
----------------------------------------------------------
2160 recursive calls
0 db block gets
5249 consistent gets
117 physical reads
0 redo size
1465638 bytes sent via SQL*Net to client
51702 bytes received via SQL*Net from client
4643 SQL*Net roundtrips to/from client
76 sorts (memory)
0 sorts (disk)
69621 rows processed
SQL> @ck_histogram.sql
SQL> select column_name, global_stats, num_distinct, num_buckets
2 from dba_tab_col_statistics where table_name = 'TB';
COLUMN_NAME GLO NUM_DISTINCT NUM_BUCKETS
------------------------------ --- ------------ -----------
KEY YES 7734 26
X YES 7736 250
SQL>
SQL> select * from
2 (
3 select substr(column_name,1,30) "Column", endpoint_number, endpoint_value
4 from dba_histograms where table_name = 'TB' order by 1 desc, 2
5 )
6 where rownum < 15;
Column ENDPOINT_NUMBER ENDPOINT_VALUE
------------------------------ --------------- --------------
X 0 1
X 1 31
X 2 62
X 3 93
X 4 124
X 5 155
X 6 186
X 7 217
X 8 248
X 9 279
X 10 310
X 11 341
X 12 372
X 13 403
14 rows selected.
|
|
|
|
|
|
| Re: Why two sets of explain plans in tkprof..ed file?? [message #141838 is a reply to message #141127] |
Wed, 12 October 2005 08:32 |
smartin
Messages: 1803
Registered: March 2005
Location: Jacksonville, Florida
|
Senior Member |
|
|
I just noticed that my query did a select count(*) whereas yours did a select *. There is potentially a big difference, because in a select count(*) oracle may not need to hit the table at all, because it can do a scan of the index to get the count. But a select * will definitely have to goto the table to get the actual data.
Anyway, I think you have enough to go on. Just use the example I posted and run it on your system and then try tweaking various things to examine their results. And remember to gather statistics like I did, I think you still have differences there. And the other points that were mentioned originally.
|
|
|
|
| Re: Why two sets of explain plans in tkprof..ed file?? [message #141929 is a reply to message #141127] |
Wed, 12 October 2005 17:05 |
wushu_kid
Messages: 7
Registered: October 2005
|
Junior Member |
|
|
1.Thanks for the great explanation.
2. I am convinced autotrace does not give me an accurate picture when it involves bind variables.
3.I get consistent sucessful result everytime I use the 10046 tracing.
4.I always use select * or select a few columns for tuning realising it might get everything from the index.
5. I enjoyed this conversation !
|
|
|
|
Goto Forum:
Current Time: Thu Apr 18 20:46:45 CDT 2024
|
] 
Blog
Search
Help
Members
Register
Login
Home
