How to compare two different SQL executions plans (question is more deeperthen seams from first look)?
- From: J.Velikanovs@xxxxxxxx
- To: oracle-l@xxxxxxxxxxxxx
- Date: Tue, 29 Jun 2004 13:57:55 +0300
PS In this mail context I am speaking about CPU resource utilization by
SQL-s. All we know that CPU resource is the main HW resource that executes
code of our systems.
I am 7 years working as Oracle DBA.
Before this day I have told Developers and other Oracle users from my
country, that the main SQL efficiency indicator is buffer gotten (LIO)
during execution of particular SQL.
Fastest from two SQL (or SQL execution plans) will be SQL with lower LIO
indicator.
HA HA HA!!!
I have two TESTCASE-s to proof that we can't use method above.
(I have suspicion that those are just two from many.We can find many
different cases.)
vvvvvvvvvvvvvvvv
vvvvvvvvvvvvvvvv
GRANT TOTAL:
I need to recall my recommendations to developers that I have given during
7 years ;)
We can't compare two SQL execution plans effectiveness by comparing LIOs.
I can't effectively use statspack reports (or any other method which use
TOPs SQL by Buffers) for identifying ineffective SQL-s.
^^^^^^^^^^^^^^^^
^^^^^^^^^^^^^^^^
It is looks like: I am going to tell Developers to go back to old method
for SQL execution plans effectiveness evaluation:
"Take your watch and just measure the execution time"
No No No! It not going to work effective then buffer gets method (Cary
Millsap perfectly described this in ?Oracle Perfomance? book).
Am in prostration ;(
I don't know that to tell peoples!
I don't see any appropriate method how to compare SQL-s effectiveness.
Any ideas?
In hope to find best method,
Thanks in advance,
Jurijs
9268222
============================================
http://otn.oracle.com/ocm/jvelikanovs.html
============================
TESTCASE 1
============================
Result from TESTCASE 1 (full test is below):
SQL1
Query=1201856
Elapsed=46.17
Query/sec=26031 blocs/sec
SQL2
Query=5616
Elapsed=42.98
Query/sec=130 blocs/sec
COMMENTS:
- Approximately the same execution time, but 200 times different LIO count
- Waits for disks in this case insignificant comparing to elapsed time,
can be
ignored
- Real SQL execution time (set timing on) is nearly the same as elapsed
!!!Conclusion!!!:
SQL1 execute LIO 200 times effective then SQL2.
Imagine if with the same Query/sec indicators SQL-s will query the same
LIO count for example
vvvvvvvvvvvvvvvv
SQL1 LIO = SQL2 LIO = 100 000 ,then
^^^^^^^^^^^^^^^^
SQL1 cpu time = 38 sec,
SQL2 cpu time = 7692 sec,
vvvvvvvvvvvvvvvv
SQL1 cpu time!= SQL2 cpu time
SQL1 cpu time * 200 = SQL2 cpu time
^^^^^^^^^^^^^^^^
LIO doesn't indicate effectiveness.
============================
TESTCASE 2
============================
SQL1 query = 23000
SQL2 query = 23000
SQL1 elapsed = 49.37 (waits ignorable)
SQL2 elapsed = 175.62 (waits ignorable)
vvvvvvvvvvvvvvvv
SQL1q=SQL2q and SQL1cpu*4=SQL2cpu
^^^^^^^^^^^^^^^^
!!!Conclusion!!!
Two SQL-s, the same LIO count, but 4 times lower cpu consumption by SQL1
then SQL2.
TESTCASE 1 (output from 10046)
====================================================
SELECT /*+ RULE */ count(m.v) from main_tab m
where
m.n in
(select f.n from
filter_tab f where f.v='a')
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ----------
----------
Parse 2 0.00 0.00 0 0 0 0
Execute 4 0.00 0.00 0 0 0 0
Fetch 4 44.48 46.17 562 1201856 0 4
------- ------ -------- ---------- ---------- ---------- ----------
----------
total 10 44.48 46.17 562 1201856 0 4
Misses in library cache during parse: 1
Optimizer mode: RULE
Parsing user id: SYS (recursive depth: 1)
Rows Row Source Operation
------- ---------------------------------------------------
2 SORT AGGREGATE (cr=801234 r=562 w=0 time=31244261 us)
800000 NESTED LOOPS (cr=801234 r=562 w=0 time=28962918 us)
800000 TABLE ACCESS FULL MAIN_TAB (cr=1230 r=562 w=0 time=3309977 us)
800000 TABLE ACCESS BY INDEX ROWID FILTER_TAB (cr=800004 r=0 w=0
time=16177875 us)
800000 INDEX UNIQUE SCAN FILTER_TAB_I1 (cr=4 r=0 w=0 time=5226711
us)(object id 9699)
Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total
Waited
---------------------------------------- Waited ----------
------------
db file scattered read 62 0.09 0.67
********************************************************************************
SELECT /*+ RULE */ count(m.v) from main_tab m
where
exists
(select v from
filter_tab f where f.n=m.n and f.v='a')
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ----------
----------
Parse 2 0.00 0.00 0 0 0 0
Execute 12 0.01 0.00 0 0 0 0
Fetch 12 42.38 42.97 1686 5616 0 12
------- ------ -------- ---------- ---------- ---------- ----------
----------
total 26 42.39 42.98 1686 5616 0 12
Misses in library cache during parse: 1
Optimizer mode: RULE
Parsing user id: SYS (recursive depth: 1)
Rows Row Source Operation
------- ---------------------------------------------------
6 SORT AGGREGATE (cr=3738 r=1686 w=0 time=28675198 us)
2400000 FILTER (cr=3738 r=1686 w=0 time=22306438 us)
2400000 TABLE ACCESS FULL MAIN_TAB (cr=3690 r=1686 w=0 time=7478255 us)
24 TABLE ACCESS BY INDEX ROWID FILTER_TAB (cr=48 r=0 w=0 time=524
us)
24 INDEX UNIQUE SCAN FILTER_TAB_I1 (cr=24 r=0 w=0 time=242
us)(object id 9699)
Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total
Waited
---------------------------------------- Waited ----------
------------
db file scattered read 186 0.04 0.33
********************************************************************************
TESTCASE 2 (output from 10046)
********************************************************************************
SELECT count(*)
from
(select * from testsort)
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ----------
----------
Parse 1 0.00 0.00 0 0 0 0
Execute 1000 0.11 0.09 0 0 0 0
Fetch 1000 49.12 49.27 0 23000 0 1000
------- ------ -------- ---------- ---------- ---------- ----------
----------
total 2001 49.23 49.37 0 23000 0 1000
Misses in library cache during parse: 1
Optimizer mode: CHOOSE
Parsing user id: SYS (recursive depth: 1)
Rows Row Source Operation
------- ---------------------------------------------------
1000 SORT AGGREGATE (cr=23000 r=0 w=0 time=49263863 us)
10000000 TABLE ACCESS FULL TESTSORT (cr=23000 r=0 w=0 time=26198104 us)
********************************************************************************
SELECT count(*)
from
(select * from testsort order by 1)
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ----------
----------
Parse 1 0.00 0.00 0 0 0 0
Execute 1000 0.21 0.20 0 0 0 0
Fetch 1000 173.38 175.41 0 23000 0 1000
------- ------ -------- ---------- ---------- ---------- ----------
----------
total 2001 173.59 175.62 0 23000 0 1000
Misses in library cache during parse: 1
Optimizer mode: CHOOSE
Parsing user id: SYS (recursive depth: 1)
Rows Row Source Operation
------- ---------------------------------------------------
1000 SORT AGGREGATE (cr=23000 r=0 w=0 time=175399815 us)
10000000 VIEW (cr=23000 r=0 w=0 time=150958286 us)
10000000 SORT ORDER BY (cr=23000 r=0 w=0 time=102002996 us)
10000000 TABLE ACCESS FULL TESTSORT (cr=23000 r=0 w=0 time=27638643
us)
********************************************************************************
----------------------------------------------------------------
Please see the official ORACLE-L FAQ: http://www.orafaq.com
----------------------------------------------------------------
To unsubscribe send email to: oracle-l-request@xxxxxxxxxxxxx
put 'unsubscribe' in the subject line.
--
Archives are at //www.freelists.org/archives/oracle-l/
FAQ is at //www.freelists.org/help/fom-serve/cache/1.html
-----------------------------------------------------------------
Other related posts:
- » How to compare two different SQL executions plans (question is more deeperthen seams from first look)?
