Re: *Measuring sql performance (elapsed time and scalability) by number of logical reads

  • From: "Radoulov, Dimitre" <cichomitiko@xxxxxxxxx>
  • To: "Wolfgang Breitling" <breitliw@xxxxxxxxxxxxx>
  • Date: Tue, 2 May 2006 16:27:39 +0200

To quote Cary Millsap (who, I believe quotes someone else) "you can't tell how
long something took by counting how often it occured". Trying to use any count
(lio, pio, BCHR, ...) as s substitute for elapsed time is misguided from the start.
Your summary below contains the answer. Remember


response time (elapsed time) = service time + wait time.

as an aside, note that there are no counts anywhere in that formula. In your
case the service time (cpu) is the difference. Due to the peculiarities of cpu
time accounting, wait time is -0.01 for both of your queries, but plan 1 takes 4
times the cpu to do the work.


Just another example why it is important to gather system statistics so that the
CBO will consider cpu time when making a plan selection. That doesn't mean
he/she/it will get it right every time, but there is a better chance with cpu
costing.


Thanks,
but the CPU costing is on.


SNAME PNAME PVAL1 PVAL2
------------------------------ ------------------------------ ---------- ----------------------------------------
SYSSTATS_INFO STATUS COMPLETED
SYSSTATS_INFO FLAGS 1
SYSSTATS_MAIN SREADTIM 1.373
SYSSTATS_MAIN MREADTIM 5.556
SYSSTATS_MAIN CPUSPEED 585
SYSSTATS_MAIN MBRC 12
SYSSTATS_MAIN MAXTHR 21000192
SYSSTATS_MAIN SLAVETHR -1




PLAN_TABLE_OUTPUT
------------------------------------------------------------------------------------------------------------------------------------

----------------------------------------------------------------------------------------------------------
| Id | Operation | Name | Rows | Bytes | Cost (%CPU)|
----------------------------------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 23 | 1472 | 43215 (1)|
|* 1 | VIEW | | 23 | 1472 | |
|* 2 | COUNT STOPKEY | | | | |
| 3 | VIEW | | 199 | 10149 | |
|* 4 | SORT UNIQUE STOPKEY | | 199 | 24079 | 43213 (1)|
| 5 | CONCATENATION | | | | |
| 6 | TABLE ACCESS BY INDEX ROWID | LESSICO_PN | 1 | 25 | 2 (50)|
| 7 | NESTED LOOPS | | 1 | 62 | 15 (7)|
| 8 | NESTED LOOPS | | 2 | 162 | 17 (6)|
| 9 | NESTED LOOPS | | 18 | 1818 | 21 (5)|
| 10 | NESTED LOOPS | | 1 | 121 | 95 (4)|
| 11 | NESTED LOOPS | | 4 | 148 | 11 (10)|
| 12 | TABLE ACCESS BY INDEX ROWID| AN_TELAI | 3 | 57 | 5 (20)|
|* 13 | INDEX RANGE SCAN | XIF04AN_TELAI | 1 | | 4 (25)|
|* 14 | INDEX RANGE SCAN | XIF02FILTRO_DATI_CATALOGO | 1 | 18 | 3 (34)|
|* 15 | INDEX RANGE SCAN | PK_VP_TAVOLE | 1 | 20 | 5 (20)|
|* 16 | INDEX RANGE SCAN | XPKASSOC_TAVOLE_PARTS | 8 | 160 | 3 (34)|
|* 17 | INDEX RANGE SCAN | XPKAN_PARTS | 3 | 57 | 3 (34)|
|* 18 | INDEX RANGE SCAN | XPKLESSICO_PN | 1 | | 2 (50)|
| 19 | NESTED LOOPS | | 1 | 121 | 95 (4)|
| 20 | NESTED LOOPS | | 18 | 1818 | 21 (5)|
| 21 | NESTED LOOPS | | 2 | 162 | 17 (6)|
| 22 | NESTED LOOPS | | 1 | 62 | 15 (7)|
| 23 | NESTED LOOPS | | 4 | 148 | 11 (10)|
| 24 | TABLE ACCESS BY INDEX ROWID | AN_TELAI | 3 | 57 | 5 (20)|
|* 25 | INDEX RANGE SCAN | XIF04AN_TELAI | 1 | | 4 (25)|
|* 26 | INDEX RANGE SCAN | XIF02FILTRO_DATI_CATALOGO | 1 | 18 | 3 (34)|
|* 27 | INDEX RANGE SCAN | XIF01LESSICO_PN | 1 | 25 | 2 (50)|
|* 28 | INDEX RANGE SCAN | XIF01AN_PARTS | 3 | 57 | 3 (34)|
|* 29 | INDEX RANGE SCAN | XIF01ASSOC_TAVOLE_PARTS | 8 | 160 | 3 (34)|
|* 30 | INDEX RANGE SCAN | PK_VP_TAVOLE | 1 | 20 | 5 (20)|
----------------------------------------------------------------------------------------------------------


Predicate Information (identified by operation id):
---------------------------------------------------

1 - filter("B"."R">0)
2 - filter(ROWNUM<=23)
4 - filter(ROWNUM<=23)
13 - access("ATI"."TARGA"='FNZ8243')
14 - access("FDC"."ID_SUBCATALOGO"=0 AND "FDC"."PV_CODE"="ATI"."PV_CODE")
15 - access("FDC"."PV_CODE"="VPT"."PV_CODE")
16 - access("VPT"."COD_TAVOLA_GRAFICA"="ATP"."COD_TAVOLA_GRAFICA")
17 - access("AP"."PART_NUMBER"="ATP"."PART_NUMBER")
filter(TRIM("AP"."PART_NUMBER") LIKE '1118647')
18 - access("LSC"."CODICE_LESSICO"="AP"."CODICE_LESSICO" AND "LSC"."LANGUAGE_CODE"=1)
25 - access("ATI"."TARGA"='FNZ8243')
26 - access("FDC"."ID_SUBCATALOGO"=0 AND "FDC"."PV_CODE"="ATI"."PV_CODE")
27 - access("LSC"."DS_LUNGA" LIKE '1118647' AND "LSC"."LANGUAGE_CODE"=1)
28 - access("LSC"."CODICE_LESSICO"="AP"."CODICE_LESSICO")
filter(LNNVL(TRIM("AP"."PART_NUMBER") LIKE '1118647'))
29 - access("AP"."PART_NUMBER"="ATP"."PART_NUMBER")
30 - access("FDC"."PV_CODE"="VPT"."PV_CODE" AND "VPT"."COD_TAVOLA_GRAFICA"="ATP"."COD_TAVOLA_GRAFICA")
filter("VPT"."COD_TAVOLA_GRAFICA"="ATP"."COD_TAVOLA_GRAFICA")





PLAN_TABLE_OUTPUT ------------------------------------------------------------------------------------------------------------------------------------

--------------------------------------------------------------------------------------------------------
| Id | Operation | Name | Rows | Bytes | Cost (%CPU)|
--------------------------------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 23 | 1472 | 2533 (4)|
|* 1 | VIEW | | 23 | 1472 | |
|* 2 | COUNT STOPKEY | | | | |
| 3 | VIEW | | 199 | 10149 | |
|* 4 | SORT UNIQUE STOPKEY | | 199 | 24079 | 2532 (4)|
|* 5 | HASH JOIN | | 199 | 24079 | 2530 (4)|
|* 6 | INDEX FAST FULL SCAN | XIF01LESSICO_PN | 2493 | 62325 | 74 (10)|
|* 7 | HASH JOIN | | 20168 | 1890K| 2453 (4)|
| 8 | NESTED LOOPS | | 20168 | 1516K| 2192 (2)|
| 9 | NESTED LOOPS | | 1070 | 60990 | 27 (4)|
| 10 | NESTED LOOPS | | 4 | 148 | 11 (10)|
| 11 | TABLE ACCESS BY INDEX ROWID| AN_TELAI | 3 | 57 | 5 (20)|
|* 12 | INDEX RANGE SCAN | XIF04AN_TELAI | 1 | | 4 (25)|
|* 13 | INDEX RANGE SCAN | XIF02FILTRO_DATI_CATALOGO | 1 | 18 | 3 (34)|
|* 14 | INDEX RANGE SCAN | PK_VP_TAVOLE | 254 | 5080 | 5 (20)|
|* 15 | INDEX RANGE SCAN | XPKASSOC_TAVOLE_PARTS | 19 | 380 | 3 (34)|
| 16 | INDEX FAST FULL SCAN | XPKAN_PARTS | 168K| 3129K| 236 (14)|
--------------------------------------------------------------------------------------------------------


Predicate Information (identified by operation id):
---------------------------------------------------

1 - filter("B"."R">0)
2 - filter(ROWNUM<=23)
4 - filter(ROWNUM<=23)
5 - access("LSC"."CODICE_LESSICO"="AP"."CODICE_LESSICO")
filter("LSC"."DS_LUNGA" LIKE '1118647' OR TRIM("AP"."PART_NUMBER") LIKE '1118647')
6 - filter("LSC"."LANGUAGE_CODE"=1)
7 - access("AP"."PART_NUMBER"="ATP"."PART_NUMBER")
12 - access("ATI"."TARGA"='FNZ8243')
13 - access("FDC"."ID_SUBCATALOGO"=0 AND "FDC"."PV_CODE"="ATI"."PV_CODE")
14 - access("FDC"."PV_CODE"="VPT"."PV_CODE")
15 - access("VPT"."COD_TAVOLA_GRAFICA"="ATP"."COD_TAVOLA_GRAFICA")




Regards,
Dimitre


--
//www.freelists.org/webpage/oracle-l


Other related posts: