| Oracle FAQ | Your Portal to the Oracle Knowledge Grid | |
 |
 | |||
| Oracle FAQ | Your Portal to the Oracle Knowledge Grid | |
|
| |||
Home -> Community -> Mailing Lists -> Oracle-L -> Re: *Measuring sql performance (elapsed time and scalability) by number of logical reads
Thanks for the feedback,
I will check the different types of logical IO in oracle.
I'm trying to undestand why I have:
No waits other than SQL*Net messages from/to client in the trace file:
$ grep WAIT xxx_ora_14318_1.trc
WAIT #1: nam='SQL*Net message to client' ela= 4 p1=1650815232 p2=1 p3=0
WAIT #1: nam='SQL*Net message from client' ela= 8115716 p1=1650815232 p2=1
p3=0
WAIT #1: nam='SQL*Net message to client' ela= 5 p1=1650815232 p2=1 p3=0 WAIT #1: nam='SQL*Net message from client' ela= 893 p1=1650815232 p2=1 p3=0 WAIT #1: nam='SQL*Net message to client' ela= 3 p1=1650815232 p2=1 p3=0 WAIT #1: nam='SQL*Net message from client' ela= 7863907 p1=1650815232 p2=1p3=0
WAIT #1: nam='SQL*Net message to client' ela= 6 p1=1650815232 p2=1 p3=0 WAIT #1: nam='SQL*Net message from client' ela= 749 p1=1650815232 p2=1 p3=0 WAIT #1: nam='SQL*Net message to client' ela= 1 p1=1650815232 p2=1 p3=0 WAIT #1: nam='SQL*Net message from client' ela= 11038250 p1=1650815232 p2=1p3=0
WAIT #1: nam='SQL*Net message to client' ela= 7 p1=1650815232 p2=1 p3=0 WAIT #1: nam='SQL*Net message from client' ela= 813 p1=1650815232 p2=1 p3=0 WAIT #1: nam='SQL*Net message to client' ela= 4 p1=1650815232 p2=1 p3=0 WAIT #1: nam='SQL*Net message from client' ela= 14939203 p1=1650815232 p2=1p3=0
WAIT #1: nam='SQL*Net message to client' ela= 7 p1=1650815232 p2=1 p3=0 WAIT #1: nam='SQL*Net message from client' ela= 1466 p1=1650815232 p2=1 p3=0 WAIT #1: nam='SQL*Net message to client' ela= 3 p1=1650815232 p2=1 p3=0 WAIT #1: nam='SQL*Net message from client' ela= 6715399 p1=1650815232 p2=1p3=0
select *
from (select a. *, rownum r
from (select distinct atp.part_number as codice,
lsc.ds_lunga as descr,
'' as TIPOOPT,
'' as b
from filtro_dati_catalogo fdc,
an_telai ati,
vp_tavole vpt,
assoc_tavole_parts atp,
an_parts ap,
lessico_pn lsc
where fdc.id_subcatalogo in (0) and ati.targa = 'FNZ8243'
and
lsc.language_code = 1 and
fdc.pv_code = ati.pv_code and
fdc.pv_code = vpt.pv_code and
vpt.cod_tavola_grafica =
atp.cod_tavola_grafica and
ap.part_number = atp.part_number and
lsc.codice_lessico = ap.codice_lessico and
(lsc.ds_lunga like '1118647' or
Trim(ap.part_number) like '1118647')
order by codice asc) a
where rownum <= 23) b
where r > 0
call count cpu elapsed disk query current
rows
Misses in library cache during parse: 1
Optimizer goal: CHOOSE
Parsing user id: 26
Rows Row Source Operation
------- ---------------------------------------------------
1 VIEW (cr=1725 r=0 w=0 time=252518 us)
1 COUNT STOPKEY (cr=1725 r=0 w=0 time=252486 us)
1 VIEW (cr=1725 r=0 w=0 time=252477 us)
1 SORT UNIQUE STOPKEY (cr=1725 r=0 w=0 time=252457 us)
1 HASH JOIN (cr=1725 r=0 w=0 time=252287 us)
2535 INDEX FAST FULL SCAN XIF01LESSICO_PN (cr=202 r=0 w=0
time=13998 us)(object id 6850)
3309 HASH JOIN (cr=1523 r=0 w=0 time=223005 us)
3309 NESTED LOOPS (cr=913 r=0 w=0 time=10605 us)
434 NESTED LOOPS (cr=13 r=0 w=0 time=883 us)
1 NESTED LOOPS (cr=7 r=0 w=0 time=155 us)
1 TABLE ACCESS BY INDEX ROWID AN_TELAI (cr=4 r=0 w=0
time=103 us)
1 INDEX RANGE SCAN XIF04AN_TELAI (cr=3 r=0 w=0 time=75
us)(object id 6771)
1 INDEX RANGE SCAN XIF02FILTRO_DATI_CATALOGO (cr=3 r=0 w=0
time=40 us)(object id 6818)
434 INDEX RANGE SCAN PK_VP_TAVOLE (cr=6 r=0 w=0 time=569
us)(object id 13282)
3309 INDEX RANGE SCAN XPKASSOC_TAVOLE_PARTS (cr=900 r=0 w=0
time=7879 us)(object id 6778)
168826 INDEX FAST FULL SCAN XPKAN_PARTS (cr=610 r=0 w=0 time=72513
us)(object id 6761)
Elapsed times include waiting on following events:
Event waited on Times Max. Wait TotalWaited
SQL*Net message to client 2 0.00 0.00 SQL*Net message from client 2 7.867.86
select *
from (select a. *, rownum r
from (select /*+ USE_NL(lsc ap) */ distinct atp.part_number as
codice,
lsc.ds_lunga as descr,
'' as TIPOOPT,
'' as b
from filtro_dati_catalogo fdc,
an_telai ati,
vp_tavole vpt,
assoc_tavole_parts atp,
an_parts ap,
lessico_pn lsc
where fdc.id_subcatalogo in (0) and ati.targa = 'FNZ8243'
and
lsc.language_code = 1 and
fdc.pv_code = ati.pv_code and
fdc.pv_code = vpt.pv_code and
vpt.cod_tavola_grafica =
atp.cod_tavola_grafica and
ap.part_number = atp.part_number and
lsc.codice_lessico = ap.codice_lessico and
(lsc.ds_lunga like '1118647' or
Trim(ap.part_number) like '1118647')
order by codice asc) a
where rownum <= 23) b
where r > 0
call count cpu elapsed disk query current
rows
Misses in library cache during parse: 1
Optimizer goal: CHOOSE
Parsing user id: 26
Rows Row Source Operation
------- ---------------------------------------------------
1 VIEW (cr=7559 r=0 w=0 time=59446 us)
1 COUNT STOPKEY (cr=7559 r=0 w=0 time=59427 us)
1 VIEW (cr=7559 r=0 w=0 time=59419 us)
1 SORT UNIQUE STOPKEY (cr=7559 r=0 w=0 time=59408 us)
1 CONCATENATION (cr=7559 r=0 w=0 time=59300 us)
1 TABLE ACCESS BY INDEX ROWID LESSICO_PN (cr=7550 r=0 w=0
time=59147 us)
3 NESTED LOOPS (cr=7549 r=0 w=0 time=59117 us)
1 NESTED LOOPS (cr=7547 r=0 w=0 time=59076 us)
3309 NESTED LOOPS (cr=913 r=0 w=0 time=12427 us)
434 NESTED LOOPS (cr=13 r=0 w=0 time=986 us)
1 NESTED LOOPS (cr=7 r=0 w=0 time=168 us)
1 TABLE ACCESS BY INDEX ROWID AN_TELAI (cr=4 r=0 w=0
time=117 us)
1 INDEX RANGE SCAN XIF04AN_TELAI (cr=3 r=0 w=0 time=83
us)(object id 6771)
1 INDEX RANGE SCAN XIF02FILTRO_DATI_CATALOGO (cr=3 r=0 w=0
time=43 us)(object id 6818)
434 INDEX RANGE SCAN PK_VP_TAVOLE (cr=6 r=0 w=0 time=640
us)(object id 13282)
3309 INDEX RANGE SCAN XPKASSOC_TAVOLE_PARTS (cr=900 r=0 w=0
time=9297 us)(object id 6778)
1 INDEX RANGE SCAN XPKAN_PARTS (cr=6634 r=0 w=0 time=40841
us)(object id 6761)
1 INDEX RANGE SCAN XPKLESSICO_PN (cr=2 r=0 w=0 time=29
us)(object id 6851)
0 NESTED LOOPS (cr=9 r=0 w=0 time=107 us)
0 NESTED LOOPS (cr=9 r=0 w=0 time=107 us)
0 NESTED LOOPS (cr=9 r=0 w=0 time=106 us)
0 NESTED LOOPS (cr=9 r=0 w=0 time=105 us)
1 NESTED LOOPS (cr=7 r=0 w=0 time=77 us)
1 TABLE ACCESS BY INDEX ROWID AN_TELAI (cr=4 r=0 w=0
time=42 us)
1 INDEX RANGE SCAN XIF04AN_TELAI (cr=3 r=0 w=0 time=27
us)(object id 6771)
1 INDEX RANGE SCAN XIF02FILTRO_DATI_CATALOGO (cr=3 r=0 w=0
time=26 us)(object id 6818)
0 INDEX RANGE SCAN XIF01LESSICO_PN (cr=2 r=0 w=0 time=21
us)(object id 6850)
0 INDEX RANGE SCAN XIF01AN_PARTS (cr=0 r=0 w=0 time=0
us)(object id 6760)
0 INDEX RANGE SCAN XIF01ASSOC_TAVOLE_PARTS (cr=0 r=0 w=0
time=0 us)(object id 6777)
0 INDEX RANGE SCAN PK_VP_TAVOLE (cr=0 r=0 w=0 time=0 us)(object
id 13282)
Elapsed times include waiting on following events:
Event waited on Times Max. Wait TotalWaited
SQL*Net message to client 2 0.00 0.00 SQL*Net message from client 2 11.0311.03
Regards,
Dimitre
P.S. Don't ask why the hint includes both tables, with /*+ USE_NL(lsc) */, /*+ USE_NL(ap) */ the plan is different.
>A logical IO is not a logical IO :) > > There are many diff. types of logical IO in oracle, and many of them > involve completely different code paths, taking diff. amounts of time to > complete. > > Regards, > Morten Egan > -----Original message----- > From: "Radoulov, Dimitre" cichomitiko_at_gmail.com > Date: Tue, 2 May 2006 14:08:53 +0200 > To: "Bernard Polarski" bpolarsk_at_yahoo.com > Subject: Re: *Measuring sql performance (elapsed time and scalability) by > number of logical reads > >> >I think you have been a bit short in the problem description. >> > >> > You just meant that all the requested data is already in buffer and no >> > physical read is needed. >> > Thanks but we have no information on the nature of the sql, the amount >> > of >> > data, the expected goal. >> > Bad or good SQL is a ratio of these. What if I read one million blocks >> > from my multi gig db block buffer >> > to return a tiny rowset for the worse ever seen SQL, it will satisfy >> > your >> > prerequisite and still be very bad. >> >> Excuse me for not being clear, I meant, theoretically speaking: >> >> SQL 1 reads n1 blocks from buffer (no physical read) to complete, elapsed >> time t1 >> SQL 2 reads n2 (where n2 > n1) blocks from buffer (no physical read) to >> complete, elapsed time t2 >> >> t1 is greater than t2 >> >> Always theoretically/hypothetical speaking: >> could anyone comment the possibile reasons behind such behaviour. >> >> >> >> Regards, >> Dimitre >> >> >> >> -- >> http://www.freelists.org/webpage/oracle-l >> >> >>
-- http://www.freelists.org/webpage/oracle-lReceived on Tue May 02 2006 - 07:31:15 CDT
 |
 |